Merge pull request 'mesh-delivery-checker: a failure's words are never "PASS"; with no cause, take the runtime's line or say so (issue 1901)' (#43) from fix/1901-package-cause into main
Reviewed-on: #43
This commit was merged in pull request #43.
This commit is contained in:
@@ -531,23 +531,98 @@ 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)
|
||||
if len(out) > MaxWords {
|
||||
out = out[len(out)-MaxWords:]
|
||||
// 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, "")
|
||||
out, passed := dropSummary(strings.TrimSpace(f.Output))
|
||||
cause := strings.TrimSpace(f.Cause)
|
||||
if cause == "" {
|
||||
cause = causeIn(out)
|
||||
}
|
||||
if c := strings.TrimSpace(f.Cause); c != "" && !strings.HasPrefix(firstLine(out), c) {
|
||||
out = c + "\n" + out
|
||||
switch {
|
||||
case 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"
|
||||
case cause == "" && out == "":
|
||||
// The build module on main sends a package that stopped (a timeout, an exit, a kill) as its "FAIL" line alone.
|
||||
cause = "the package failed with no test to name and no panic, signal or build error in its output (an older build module sent no cause)"
|
||||
}
|
||||
if len(cause) > MaxCause {
|
||||
cause = strings.ToValidUTF8(cause[:MaxCause], "") + "..."
|
||||
}
|
||||
// The words keep MaxWords exactly: the cause and its newline, the marker and the kept lines (review round 1).
|
||||
budget := MaxWords
|
||||
if cause != "" {
|
||||
budget -= len(cause) + 1
|
||||
}
|
||||
if len(out) > budget {
|
||||
const marker = "... "
|
||||
tail := out[len(out)-(budget-len(marker)):]
|
||||
// Start on a whole line, and a whole character.
|
||||
if i := strings.IndexByte(tail, '\n'); i >= 0 {
|
||||
tail = strings.TrimLeft(tail[i:], "\n")
|
||||
}
|
||||
out = marker + strings.ToValidUTF8(tail, "")
|
||||
}
|
||||
if cause != "" && !strings.HasPrefix(firstLine(out), cause) {
|
||||
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 {
|
||||
// go's exact forms only (review round 1): "PASS" or "FAIL" alone, "ok \t<pkg>\t<time>", "FAIL\t<pkg>\t<time>".
|
||||
switch t := strings.TrimRight(l, "\r"); {
|
||||
case t == "PASS":
|
||||
passed = true
|
||||
case t == "FAIL", strings.HasPrefix(t, "ok \t"), strings.HasPrefix(t, "FAIL\t"):
|
||||
default:
|
||||
kept = append(kept, l)
|
||||
}
|
||||
}
|
||||
return strings.TrimSpace(strings.Join(kept, "\n")), passed
|
||||
}
|
||||
|
||||
// causeIn is a race the race detector reported, as its heading, its access and the frame that made it ("WARNING: DATA
|
||||
// RACE: Write at 0x... by goroutine 9 in pkg.F.func1()"); else the first "panic:", "fatal error:" or "signal:" line of a
|
||||
// failure's output, in that order; or "". **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 causeIn(out string) string {
|
||||
lines := strings.Split(out, "\n")
|
||||
for i, l := range lines {
|
||||
if strings.TrimRight(l, "\r") != "WARNING: DATA RACE" {
|
||||
continue
|
||||
}
|
||||
words := "WARNING: DATA RACE"
|
||||
if i+1 < len(lines) && strings.TrimSpace(lines[i+1]) != "" {
|
||||
words += ": " + strings.TrimSuffix(strings.TrimSpace(lines[i+1]), ":")
|
||||
if i+2 < len(lines) && strings.HasPrefix(lines[i+2], " ") {
|
||||
words += " in " + strings.TrimSpace(lines[i+2])
|
||||
}
|
||||
}
|
||||
return words
|
||||
}
|
||||
for _, prefix := range []string{"panic: ", "fatal error: ", "signal: "} {
|
||||
for _, l := range lines {
|
||||
if l = strings.TrimRight(l, "\r"); 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") {
|
||||
|
||||
@@ -0,0 +1,92 @@
|
||||
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, TestMain exiting 2 after m.Run, and TestMain racing 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"
|
||||
// TestMain racing after m.Run passed, under go test -race (go-test-json-pkg-racemain.jsonl).
|
||||
oldPassThenRace = "PASS\n==================\nWARNING: DATA RACE\nWrite at 0x000000836428 by goroutine 9:\n example.com/racemain.TestMain.func1()\n /tmp/fix-1901b/racemain/p_test.go:15 +0x24\nPrevious write at 0x000000836428 by main goroutine:\n example.com/racemain.TestMain()\n /tmp/fix-1901b/racemain/p_test.go:16 +0x44\n main.main()\n _testmain.go:48 +0x171\nGoroutine 9 (running) created at:\n example.com/racemain.TestMain()\n /tmp/fix-1901b/racemain/p_test.go:15 +0x37\n main.main()\n _testmain.go:48 +0x171\n==================\nFound 1 data race(s)\nFAIL\texample.com/racemain\t1.031s"
|
||||
)
|
||||
|
||||
// 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"},
|
||||
{"race after the tests", oldPassThenRace, "WARNING: DATA RACE: Write at 0x000000836428 by goroutine 9 in example.com/racemain.TestMain.func1()"},
|
||||
{"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)
|
||||
}
|
||||
}
|
||||
|
||||
// The build module on main sends a package that stopped (a timeout, an exit, a kill) as only go test's last line, with no
|
||||
// cause: the words then say so, never nothing (review round 1). Each output is what that build module sends for the
|
||||
// capture of the same name (go-test-json-pkg-timeout, -exiting, -killed): the package's own output, its "FAIL" line.
|
||||
func TestAPackageStoppedWithOnlyItsFailLineIsStillWorded(t *testing.T) { // 1901/AC5
|
||||
for _, out := range []string{"FAIL\texample.com/timeout\t2.017s", "FAIL\texample.com/exiting\t0.006s", "FAIL\texample.com/killed\t0.006s"} {
|
||||
v := levelFailure(&target{}, "integration", Tested{Failed: []Failure{{Package: "example.com/x", Output: out}}})
|
||||
if !strings.HasPrefix(v.Failed.Words, "the package failed with no test to name and no panic, signal or build error in its output") {
|
||||
t.Errorf("1901/AC5: %q is worded %q", out, v.Failed.Words)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// A line of the test's own that starts as go's summary does, or that holds a runtime's words indented, is not taken for
|
||||
// either (review round 1): go prints its summary in exact forms and the runtime's lines at column 0.
|
||||
func TestOnlyGosExactFormsAreSummaryOrCause(t *testing.T) { // 1901/AC5
|
||||
out := " x_test.go:3: ok so far\nok then: the seat is free\n panic: child retried and recovered\npanic: the real one\nFAIL\tp\t1.0s"
|
||||
v := levelFailure(&target{}, "unit", Tested{Failed: []Failure{{Package: "p", Output: out}}})
|
||||
if !strings.HasPrefix(v.Failed.Words, "panic: the real one") || !strings.Contains(v.Failed.Words, "ok then: the seat is free") {
|
||||
t.Errorf("1901/AC5: words = %q", v.Failed.Words)
|
||||
}
|
||||
}
|
||||
|
||||
// The words keep MaxWords exactly, counting the cause, the marker and the newlines (review round 1).
|
||||
func TestTheWordsKeepTheirBoundExactly(t *testing.T) { // 1901/AC5
|
||||
for _, cause := range []string{"", "a cause", strings.Repeat("c", 3000)} {
|
||||
for _, n := range []int{100, 170, 171, 172, 500} {
|
||||
f := Failure{Package: "p", Test: "TestX", Cause: cause, Output: strings.Repeat("a log line of twenty\n", n) + "the end"}
|
||||
if w := failureWords(f); len(w) > MaxWords {
|
||||
t.Errorf("1901/AC5: cause %d bytes, %d lines: words are %d bytes, bound %d", len(cause), n, len(w), MaxWords)
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user