novox/mesh-catalog
18
0
Fork 0
Code Issues Pull Requests 3 Actions Packages Projects Releases Wiki Activity

mesh-build-go: a failed test keeps its last lines and its error line, not its first fifteen (issue 1901)

Browse Source
This commit is contained in:
jschoubben
2026-10-23 18:07:23 +02:00
parent 0f768bc97b
commit 6eacbd160d
3 changed files with 113 additions and 8 deletions
Download Patch File Download Diff File Expand all files Collapse all files
modules/mesh-build-go/cmd/mesh-build-go/failure_words_test.go
+48
View File
@@ -0,0 +1,48 @@
package main
import (
"os"
"strings"
"testing"
)
// A failed test keeps the lines that say why it failed, not the lines it logged first (issue 1901). The fixture is
// the real `go test -json` of a test that logs a line and then fails with a multi-line t.Fatalf.
func TestAFailedTestKeepsItsFatalMessageAfterItsLogLines(t *testing.T) {
raw, err := os.ReadFile("testdata/captured/go-test-json-log-then-fatal.jsonl")
if err != nil {
t.Fatal(err)
}
res := &TestResult{}
rd := newReader(res, ".")
rd.read(string(raw))
rd.finish()
if len(res.Failed) != 1 {
t.Fatalf("failures = %+v, want one", res.Failed)
}
f := res.Failed[0]
for _, want := range []string{"3 subscription(s) derive to a subject no emitter owns:", "a.b.c", "d.e.f", "g.h.i"} {
if !strings.Contains(f.Output, want) {
t.Errorf("1901/AC1: output lacks %q: %q", want, f.Output)
}
}
if want := "3 subscription(s) derive to a subject no emitter owns:"; f.Cause != want && !strings.HasSuffix(f.Cause, want) {
t.Errorf("1901/AC2: cause = %q, want the t.Fatalf line, not the t.Logf line", f.Cause)
}
}
// A failure longer than the bound keeps its last lines, where the cause is, and says how many earlier lines it dropped.
func TestAFailureLongerThanTheBoundKeepsItsLastLines(t *testing.T) {
var lines []string
for i := 0; i < 400; i++ {
lines = append(lines, " x_test.go:1: log line "+strings.Repeat("y", 40))
}
lines = append(lines, " x_test.go:9: the real cause", "--- FAIL: TestX (0.00s)")
out := clip(lines)
if len(out) > outputBytes+100 {
t.Errorf("1901/AC1: kept %d bytes, bound is %d", len(out), outputBytes)
}
if !strings.HasSuffix(out, "the real cause\n--- FAIL: TestX (0.00s)") || !strings.HasPrefix(out, "... (") {
t.Errorf("1901/AC1: out = %q...%q", out[:40], out[len(out)-60:])
}
}
modules/mesh-build-go/cmd/mesh-build-go/levels.go
+52 -8
View File
@@ -9,6 +9,7 @@ import (
"bufio"
"encoding/json"
"fmt"
"regexp"
"sort"
"strings"
"time"
@@ -49,11 +50,13 @@ type TestTime struct {
}
// Failure is a test that failed, or a package that failed with no test to name (a build that failed, a TestMain that
// panicked); Output is the first lines it wrote.
// panicked); Output is the last lines it wrote, up to outputBytes (issue 1901), and Cause the first line of what the
// test reported as its error (t.Error, t.Fatal), without its file and line, when go test said which lines those were.
type Failure struct {
Package string `json:"package"`
Test string `json:"test,omitempty"`
Output string `json:"output,omitempty"`
Cause string `json:"cause,omitempty"`
}
// TestResult is what a test step passes with.
@@ -96,13 +99,20 @@ type event struct {
Package string
Test string
Output string
OutputType string // "error" for a t.Error or t.Fatal message, "error-continue" for its further lines (go test -json)
ImportPath string
FailedBuild string
Elapsed float64
}
// outputLines is how many lines of output a failure keeps.
const outputLines = 15
// outputBytes is the most a failure keeps of its output, and outputLineBytes the most of one line. **A failure keeps its
// last lines** (issue 1901): a test logs before it fails, so the lines that say why are at the end, and the first
// fifteen lines kept before lost them (the verdict of group r4g kept a t.Logf line, not the t.Fatalf after it). Four
// kilobytes holds a long assertion message and stays far under a bus message's or a verdict's bound.
const (
outputBytes = 4096
outputLineBytes = 1024
)
// reader collects the events of one go.mod directory's `go test -json` into a result.
type reader struct {
@@ -113,13 +123,14 @@ type reader struct {
builds map[string][]string // build output by import path
pkgOut map[string][]string
testOut map[string][]string // by package + "\x00" + test
causes map[string]string // the first error line of a test, by the same key
times []TestTime
failedIn map[string]bool // packages with a failed test
}
func newReader(res *TestResult, dir string) *reader {
return &reader{res: res, dir: dir, pkgs: map[string]*PackageResult{}, builds: map[string][]string{},
pkgOut: map[string][]string{}, testOut: map[string][]string{}, failedIn: map[string]bool{}}
pkgOut: map[string][]string{}, testOut: map[string][]string{}, causes: map[string]string{}, failedIn: map[string]bool{}}
}
// read takes go test's output. Lines that are not events are kept for a failure that has nothing else to say.
@@ -183,6 +194,9 @@ func (r *reader) event(ev event) {
switch ev.Action {
case "output":
r.testOut[key] = keep(r.testOut[key], ev.Output)
if ev.OutputType == "error" && r.causes[key] == "" {
r.causes[key] = errorWords(ev.Output)
}
case "pass", "fail", "skip":
p := r.pkg(ev.Package)
p.Tests++
@@ -193,17 +207,47 @@ func (r *reader) event(ev event) {
r.times = append(r.times, TestTime{Package: ev.Package, Test: ev.Test, Elapsed: ev.Elapsed})
if ev.Action == "fail" {
r.failedIn[ev.Package] = true
r.res.Failed = append(r.res.Failed, Failure{Package: ev.Package, Test: ev.Test, Output: clip(r.testOut[key])})
r.res.Failed = append(r.res.Failed, Failure{Package: ev.Package, Test: ev.Test, Output: clip(r.testOut[key]), Cause: r.causes[key]})
}
}
}
}
// clip joins the last lines of a failure's output that fit outputBytes, each cut to outputLineBytes, and says how many
// earlier lines it left out.
func clip(lines []string) string {
if len(lines) > outputLines {
lines = append(lines[:outputLines:outputLines], fmt.Sprintf("... (%d more lines)", len(lines)-outputLines))
size, from := 0, len(lines)
for from > 0 {
n := len(cutLine(lines[from-1])) + 1
if size+n > outputBytes && from < len(lines) {
break
}
size += n
from--
}
return strings.Join(lines, "\n")
kept := make([]string, 0, len(lines)-from+1)
if from > 0 {
kept = append(kept, fmt.Sprintf("... (%d earlier lines)", from))
}
for _, l := range lines[from:] {
kept = append(kept, cutLine(l))
}
return strings.Join(kept, "\n")
}
// cutLine cuts a line to outputLineBytes, on a character boundary.
func cutLine(l string) string {
if len(l) <= outputLineBytes {
return l
}
return strings.ToValidUTF8(l[:outputLineBytes], "") + "..."
}
var fileAndLine = regexp.MustCompile(`^\S+\.go:\d+: `)
// errorWords is the words of an error line of a test: trimmed, without the file and line go test put before them.
func errorWords(out string) string {
return strings.TrimSpace(fileAndLine.ReplaceAllString(strings.TrimSpace(out), ""))
}
// finish moves what was read into the result: the packages in order, a failure for each failed package that has no
modules/mesh-build-go/cmd/mesh-build-go/testdata/captured/go-test-json-log-then-fatal.jsonl
Vendored
+13
View File
@@ -0,0 +1,13 @@
{"Action":"start","Package":"x"}
{"Action":"run","Package":"x","Test":"TestThree"}
{"Action":"output","Package":"x","Test":"TestThree","Output":"=== RUN TestThree\n","OutputType":"frame"}
{"Action":"output","Package":"x","Test":"TestThree","Output":" a_test.go:4: judged against /var/lib/mesh-build-go-work/id/beside/mesh-catalog as cloned\n"}
{"Action":"output","Package":"x","Test":"TestThree","Output":" a_test.go:5: 3 subscription(s) derive to a subject no emitter owns:\n","OutputType":"error"}
{"Action":"output","Package":"x","Test":"TestThree","Output":" a.b.c\n","OutputType":"error-continue"}
{"Action":"output","Package":"x","Test":"TestThree","Output":" d.e.f\n","OutputType":"error-continue"}
{"Action":"output","Package":"x","Test":"TestThree","Output":" g.h.i\n","OutputType":"error-continue"}
{"Action":"output","Package":"x","Test":"TestThree","Output":"--- FAIL: TestThree (0.00s)\n","OutputType":"frame"}
{"Action":"fail","Package":"x","Test":"TestThree","Elapsed":0}
{"Action":"output","Package":"x","Output":"FAIL\n","OutputType":"frame"}
{"Action":"output","Package":"x","Output":"FAIL\tx\t0.002s\n","OutputType":"frame"}
{"Action":"fail","Package":"x","Elapsed":0.002}