mesh-catalog/modules/mesh-build-go/cmd/mesh-build-go/levels.go

package main

// The judging of a test level (novox/hq ADR 0445 §2 §3; issues 1290 and 1486): `go test -json` read into a result
// that says, per package, what ran and for how long, which tests failed and why, and whether the level kept its
// bound. A level that failed is still a finished step: the verdict is in the result, and a step that ends failed is a
// step that could not run.

import (
	"bufio"
	"encoding/json"
	"fmt"
	"regexp"
	"sort"
	"strings"
	"time"
)

// The two levels (ADR 0445 §2).
const (
	LevelUnit        = "unit"
	LevelIntegration = "integration"
)

// UnitBound is the unit level's one bound: its running time, five seconds for the level, no setup (ADR 0445 §3). The
// level's time is that of its slowest package, as packages run side by side, the compile not counted.
const UnitBound = 5 * time.Second

// Bounds are the bounds a level is judged by: Setup is the time of everything before the tests run (compiling,
// starting the store and the bus; the unit level has none) and Run the tests' own time.
type Bounds struct {
	Setup, Run time.Duration
}

// PackageResult is one package's part of a level.
type PackageResult struct {
	Dir     string  `json:"dir"`
	Package string  `json:"package"`
	Passed  bool    `json:"passed"`
	Elapsed float64 `json:"elapsed"`
	Tests   int     `json:"tests"`
	// NoTests is a package with no test files (at this level: a file with the other level's build tag is none).
	NoTests bool `json:"no_tests,omitempty"`
}

// TestTime is one test and the time it took.
type TestTime struct {
	Package string  `json:"package"`
	Test    string  `json:"test"`
	Elapsed float64 `json:"elapsed"`
}

// 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 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.
type TestResult struct {
	Level  string `json:"level"`
	Passed bool   `json:"passed"`
	// Why says, in words, why the level failed, or that it has no tests.
	Why      string          `json:"why,omitempty"`
	NoTests  bool            `json:"no_tests,omitempty"`
	Tests    int             `json:"tests"`
	Skipped  int             `json:"skipped"`
	Packages []PackageResult `json:"packages"`
	// Elapsed is the level's running time in seconds: the slowest package's.
	Elapsed float64 `json:"elapsed"`
	// Setup is the level's setup time in seconds, when it has a setup.
	Setup float64 `json:"setup,omitempty"`
	// Lint is the unit level's gofmt and go vet time in seconds, before its tests (ADR 0529 §1).
	Lint float64 `json:"lint,omitempty"`
	// Bound and SetupBound are the bounds the level was judged by, in seconds.
	Bound      float64    `json:"bound"`
	SetupBound float64    `json:"setup_bound,omitempty"`
	Slowest    []TestTime `json:"slowest,omitempty"`
	Failed     []Failure  `json:"failed,omitempty"`
	// Store and Bus are what the integration level ran against: the postgres major version and the nats-server
	// version (ADR 0470 §4).
	// OverBound says a bound was kept no longer, and OverWhich which: setup, run or both. The level's verdict, Passed, is
	// the tests' own: the checker judges the bounds (ADR 0453 §9), with the slowest tests this result names.
	OverBound bool   `json:"over_bound"`
	OverWhich string `json:"over_which,omitempty"`
	Store     string `json:"store,omitempty"`
	Bus       string `json:"bus,omitempty"`
	// JudgedBy is the program that ran the level (ADR 0535 §5): "installed", or "candidate <merge commit>" under the
	// runner workspace.
	JudgedBy string `json:"judged_by,omitempty"`
}

// event is one line of `go test -json` (test2json, and the build events go test adds).
type event struct {
	Action      string
	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
}

// 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 {
	res      *TestResult
	dir      string
	pkgs     map[string]*PackageResult
	order    []string
	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{}, 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.
func (r *reader) read(out string) (noise []string) {
	sc := bufio.NewScanner(strings.NewReader(out))
	sc.Buffer(make([]byte, 1<<20), 1<<26)
	for sc.Scan() {
		var ev event
		if err := json.Unmarshal(sc.Bytes(), &ev); err != nil {
			if l := strings.TrimSpace(sc.Text()); l != "" {
				noise = append(noise, l)
			}
			continue
		}
		r.event(ev)
	}
	return noise
}

func (r *reader) pkg(name string) *PackageResult {
	p := r.pkgs[name]
	if p == nil {
		p = &PackageResult{Dir: r.dir, Package: name}
		r.pkgs[name] = p
		r.order = append(r.order, name)
	}
	return p
}

func keep(lines []string, out string) []string {
	if t := strings.TrimRight(out, "\r\n"); t != "" && !strings.HasPrefix(t, "=== ") {
		lines = append(lines, t)
	}
	return lines
}

func (r *reader) event(ev event) {
	switch {
	case ev.Package == "" && ev.ImportPath != "":
		if ev.Action == "build-output" {
			r.builds[ev.ImportPath] = keep(r.builds[ev.ImportPath], ev.Output)
		}
	case ev.Package == "":
	case ev.Test == "":
		p := r.pkg(ev.Package)
		switch ev.Action {
		case "output":
			r.pkgOut[ev.Package] = keep(r.pkgOut[ev.Package], ev.Output)
		case "pass":
			p.Passed, p.Elapsed = true, ev.Elapsed
		case "fail":
			p.Passed, p.Elapsed = false, ev.Elapsed
			if ev.FailedBuild != "" {
				r.pkgOut[ev.Package] = append(r.builds[ev.FailedBuild], r.pkgOut[ev.Package]...)
			}
		case "skip":
			p.Passed, p.NoTests = true, true
		}
	default:
		key := ev.Package + "\x00" + ev.Test
		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++
			r.res.Tests++
			if ev.Action == "skip" {
				r.res.Skipped++
			}
			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.causes[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. **When it leaves lines out, its first line is still a real one** (issue 1901/AC3): the failure's
// cause, or failing that the first non-empty line of the output, then the marker. An older checker takes only the first
// non-empty line of the output, and a marker there would be less than the older pair kept.
func clip(lines []string, cause string) string {
	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--
	}
	kept := make([]string, 0, len(lines)-from+1)
	if from > 0 {
		head := strings.TrimSpace(cause)
		for i := 0; head == "" && i < from; i++ {
			head = strings.TrimSpace(lines[i])
		}
		if head != "" {
			kept = append(kept, cutLine(head))
		}
		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
// failed test to name it, and the tests' times.
func (r *reader) finish() {
	for _, name := range r.order {
		p := r.pkgs[name]
		if !p.Passed && !r.failedIn[name] {
			r.res.Failed = append(r.res.Failed, Failure{Package: name, Output: clip(r.pkgOut[name], "")})
		}
		if !p.NoTests && p.Elapsed > r.res.Elapsed {
			r.res.Elapsed = p.Elapsed
		}
		r.res.Packages = append(r.res.Packages, *p)
	}
	r.res.Slowest = append(r.res.Slowest, r.times...)
}

// judge sets Passed and Why from what was read and the bounds. A level with no failure, over no bound, passes; with no
// test at all it says the repository has none at this level, which is neither a failure nor a warning (ADR 0445 §1).
func (res *TestResult) judge(b Bounds) {
	sort.SliceStable(res.Slowest, func(i, j int) bool { return res.Slowest[i].Elapsed > res.Slowest[j].Elapsed })
	if len(res.Slowest) > 5 {
		res.Slowest = res.Slowest[:5]
	}
	res.Bound, res.SetupBound = b.Run.Seconds(), b.Setup.Seconds()
	var why, over []string
	if n := len(res.Failed); n > 0 {
		names := []string{}
		for _, f := range res.Failed {
			names = append(names, strings.TrimSpace(f.Package+" "+f.Test))
		}
		why = append(why, fmt.Sprintf("%d failed: %s", n, strings.Join(names, ", ")))
	}
	res.Passed = len(res.Failed) == 0
	if b.Setup > 0 && res.Setup > b.Setup.Seconds() {
		over = append(over, "setup")
		why = append(why, fmt.Sprintf("the %s level's setup took %.2f s, over its setup bound of %s", res.Level, res.Setup, seconds(b.Setup)))
	}
	if b.Run > 0 && res.Elapsed > b.Run.Seconds() {
		over = append(over, "run")
		slow := []string{}
		for _, s := range res.Slowest {
			slow = append(slow, fmt.Sprintf("%s %s (%.2f s)", s.Package, s.Test, s.Elapsed))
		}
		why = append(why, fmt.Sprintf("the %s level took %.2f s, over its bound of %s; the slowest tests: %s", res.Level, res.Elapsed, seconds(b.Run), strings.Join(slow, ", ")))
	}
	res.OverBound, res.OverWhich = len(over) > 0, strings.Join(over, ",")
	res.NoTests = res.Tests == 0 && len(res.Failed) == 0
	switch {
	case len(why) > 0:
		res.Why = strings.Join(why, "; ")
	case res.NoTests:
		res.Why = "the repository has no tests at the " + res.Level + " level"
	}
}

// seconds is a duration as seconds, without trailing zeros: "5 s", "0.01 s".
func seconds(d time.Duration) string {
	return strings.TrimRight(strings.TrimRight(fmt.Sprintf("%.3f", d.Seconds()), "0"), ".") + " s"
}