cmd/testwrapper: auto-retry every failing test
Previously, testwrapper only retried tests explicitly annotated with flakytest.Mark. Authors don't pre-emptively mark tests that haven't flaked yet, so the first flake of a brand-new test failed CI even when a re-run would have passed. testwrapper now retries every failing test within a per-test wall-clock budget (default: 5 minute per-attempt timeout capped at 1.5x the first failure duration, 10 minute total). A test that fails and then passes on retry is reported as flaky; a test that never passes within the budget remains a real failure (exit non-zero). For flakeapp's existing log scraping, the wire format is preserved: the "flakytest failures JSON:" line is now emitted only for tests that ultimately flaked (passed on retry). Unmarked tests get a fake issue URL of the form https://github.com/{owner}/{repo}/issues/UNKNOWN where owner/repo is detected from GITHUB_REPOSITORY, the local git remote, or falls back to tailscale/tailscale. A new "permanent test failures JSON:" line is emitted for tests that never passed; flakeapp ignores it for now (a follow-up can teach it to record real failures separately). flakytest.Mark stays as an opt-in API: still useful for tracking a known-flaky test against a real issue and for TS_SKIP_FLAKY_TESTS. Updates tailscale/corp#38960 Change-Id: I56dfc9b023486d239f60793a53e9690578ce8017 Signed-off-by: Brad Fitzpatrick <bradfitz@tailscale.com>
This commit is contained in:
committed by
Brad Fitzpatrick
parent
2ee9eacb94
commit
d961e44856
@@ -1,9 +1,14 @@
|
||||
// Copyright (c) Tailscale Inc & contributors
|
||||
// SPDX-License-Identifier: BSD-3-Clause
|
||||
|
||||
// Package flakytest contains test helpers for marking a test as flaky. For
|
||||
// tests run using cmd/testwrapper, a failed flaky test will cause tests to be
|
||||
// re-run a few time until they succeed or exceed our iteration limit.
|
||||
// Package flakytest contains test helpers for marking a test as flaky.
|
||||
//
|
||||
// Marking a test with [Mark] is not required for cmd/testwrapper to retry
|
||||
// failed tests; the wrapper retries any failure within a per-test time
|
||||
// budget and reports a test as flaky if it ever passes on retry. Mark is
|
||||
// useful for tracking a known-flaky test against a GitHub issue and for the
|
||||
// TS_SKIP_FLAKY_TESTS skip behavior used to keep CI green when a flake is
|
||||
// being investigated.
|
||||
package flakytest
|
||||
|
||||
import (
|
||||
|
||||
+472
-153
@@ -1,10 +1,17 @@
|
||||
// Copyright (c) Tailscale Inc & contributors
|
||||
// SPDX-License-Identifier: BSD-3-Clause
|
||||
|
||||
// testwrapper is a wrapper for retrying flaky tests. It is an alternative to
|
||||
// `go test` and re-runs failed marked flaky tests (using the flakytest pkg). It
|
||||
// takes different arguments than go test and requires the first positional
|
||||
// argument to be the pattern to test.
|
||||
// testwrapper is a wrapper for go test that automatically retries failing
|
||||
// tests to detect flakiness.
|
||||
//
|
||||
// Any failed test is treated as potentially flaky and re-run within a per-test
|
||||
// time budget (see the perAttempt* and perTestBudget constants). A test that
|
||||
// fails and then later passes is reported as flaky. A test that never passes
|
||||
// within the budget is a real failure and causes a non-zero exit.
|
||||
//
|
||||
// The flakytest package's Mark API is no longer required for retries — it is
|
||||
// kept for explicit issue tracking and for the TS_SKIP_FLAKY_TESTS skip
|
||||
// behavior.
|
||||
package main
|
||||
|
||||
import (
|
||||
@@ -29,11 +36,20 @@ import (
|
||||
"time"
|
||||
|
||||
"tailscale.com/cmd/testwrapper/flakytest"
|
||||
"tailscale.com/util/slicesx"
|
||||
)
|
||||
|
||||
// Per-test retry policy. See package doc comment.
|
||||
const (
|
||||
maxAttempts = 3
|
||||
// perAttemptCap is the upper bound on the per-retry-attempt -timeout we set
|
||||
// when running a single failed test.
|
||||
perAttemptCap = 5 * time.Minute
|
||||
// perAttemptFloor is the lower bound on the per-retry-attempt -timeout, to
|
||||
// give the test binary time to start.
|
||||
perAttemptFloor = 30 * time.Second
|
||||
// maxRetries caps the number of retry attempts for a single test. It
|
||||
// guards against re-running a very fast test thousands of times within
|
||||
// perTestBudget.
|
||||
maxRetries = 10
|
||||
|
||||
// raceDetectorMarkerLine is the first line of every Go race
|
||||
// detector report, emitted at column 0. We look for it as a
|
||||
@@ -44,11 +60,65 @@ const (
|
||||
raceDetectorMarkerLine = "WARNING: DATA RACE\n"
|
||||
)
|
||||
|
||||
// Tunables for the per-test retry budget. These default to production values
|
||||
// but can be overridden via env vars, primarily for tests of testwrapper
|
||||
// itself.
|
||||
var (
|
||||
// perTestBudget is the total wall-clock time we are willing to spend
|
||||
// retrying a single test before giving up. Override via
|
||||
// TS_TESTWRAPPER_BUDGET (a time.Duration string).
|
||||
perTestBudget = envDuration("TS_TESTWRAPPER_BUDGET", 10*time.Minute)
|
||||
// minRetries is the minimum number of retry attempts we make for a failed
|
||||
// test, regardless of perTestBudget. Override via TS_TESTWRAPPER_MIN_RETRIES.
|
||||
minRetries = envInt("TS_TESTWRAPPER_MIN_RETRIES", 2)
|
||||
)
|
||||
|
||||
func envDuration(key string, def time.Duration) time.Duration {
|
||||
s := os.Getenv(key)
|
||||
if s == "" {
|
||||
return def
|
||||
}
|
||||
d, err := time.ParseDuration(s)
|
||||
if err != nil {
|
||||
log.Panicf("invalid %s=%q: %v", key, s, err)
|
||||
}
|
||||
return d
|
||||
}
|
||||
|
||||
func envInt(key string, def int) int {
|
||||
s := os.Getenv(key)
|
||||
if s == "" {
|
||||
return def
|
||||
}
|
||||
n, err := strconv.Atoi(s)
|
||||
if err != nil {
|
||||
log.Panicf("invalid %s=%q: %v", key, s, err)
|
||||
}
|
||||
return n
|
||||
}
|
||||
|
||||
// flakeUnknownIssueSlug is the trailing path of the fake GitHub issue URL we
|
||||
// record for tests that turned out flaky but were not explicitly marked with
|
||||
// flakytest.Mark. flakeapp records this as a flake occurrence with no real
|
||||
// issue.
|
||||
const flakeUnknownIssueSlug = "/issues/UNKNOWN"
|
||||
|
||||
// testOutcome is the outcome of a single test (or package) run. Its string
|
||||
// values match the Action field in `go test -json` output.
|
||||
type testOutcome string
|
||||
|
||||
const (
|
||||
outcomeUnknown testOutcome = ""
|
||||
outcomePass testOutcome = "pass"
|
||||
outcomeFail testOutcome = "fail"
|
||||
outcomeSkip testOutcome = "skip"
|
||||
)
|
||||
|
||||
type testAttempt struct {
|
||||
pkg string // "tailscale.com/types/key"
|
||||
testName string // "TestFoo"
|
||||
outcome string // "pass", "fail", "skip"
|
||||
cached bool // whether package-level (non-testName specific) was pass due to being cached
|
||||
pkg string // "tailscale.com/types/key"
|
||||
testName string // "TestFoo"
|
||||
outcome testOutcome // outcomePass, outcomeFail, outcomeSkip, or outcomeUnknown
|
||||
cached bool // whether package-level (non-testName specific) was pass due to being cached
|
||||
logs bytes.Buffer
|
||||
start, end time.Time
|
||||
isMarkedFlaky bool // set if the test is marked as flaky
|
||||
@@ -61,8 +131,19 @@ type testAttempt struct {
|
||||
pkgFinished bool
|
||||
}
|
||||
|
||||
// failedTest tracks per-test state across the retry phase.
|
||||
type failedTest struct {
|
||||
pkg, testName string
|
||||
firstFailDuration time.Duration
|
||||
issueURL string // non-empty iff the test called flakytest.Mark
|
||||
|
||||
attempts int // number of retry attempts run so far
|
||||
totalRetryElapsed time.Duration // total time spent across retry attempts
|
||||
everPassed bool // a retry attempt passed
|
||||
}
|
||||
|
||||
// packageTests describes what to run.
|
||||
// It's also JSON-marshalled to output for analysys tools to parse
|
||||
// It's also JSON-marshalled to output for analysis tools to parse,
|
||||
// so the fields are all exported.
|
||||
// TODO(bradfitz): move this type to its own types package?
|
||||
type packageTests struct {
|
||||
@@ -196,7 +277,7 @@ func runTests(ctx context.Context, attempt int, pt *packageTests, goTestArgs, te
|
||||
return err
|
||||
}
|
||||
if len(shardTests) == 0 {
|
||||
ch <- &testAttempt{pkg: pt.Pattern, outcome: "skip", pkgFinished: true}
|
||||
ch <- &testAttempt{pkg: pt.Pattern, outcome: outcomeSkip, pkgFinished: true}
|
||||
return nil
|
||||
}
|
||||
quoted := make([]string, len(shardTests))
|
||||
@@ -262,14 +343,14 @@ func runTests(ctx context.Context, attempt int, pt *packageTests, goTestArgs, te
|
||||
pkgTests[""].logs.WriteString(goOutput.Output)
|
||||
case "build-fail", "fail", "pass", "skip":
|
||||
for _, test := range pkgTests {
|
||||
if test.testName != "" && test.outcome == "" {
|
||||
test.outcome = "fail"
|
||||
if test.testName != "" && test.outcome == outcomeUnknown {
|
||||
test.outcome = outcomeFail
|
||||
ch <- test
|
||||
}
|
||||
}
|
||||
outcome := goOutput.Action
|
||||
if outcome == "build-fail" {
|
||||
outcome = "fail"
|
||||
outcome := testOutcome(goOutput.Action)
|
||||
if goOutput.Action == "build-fail" {
|
||||
outcome = outcomeFail
|
||||
}
|
||||
pkgTests[""].logs.WriteString(goOutput.Output)
|
||||
// If a data race was detected anywhere in this
|
||||
@@ -349,7 +430,7 @@ func runTests(ctx context.Context, attempt int, pt *packageTests, goTestArgs, te
|
||||
}
|
||||
case "skip", "pass", "fail":
|
||||
pkgTests[testName].end = goOutput.Time
|
||||
pkgTests[testName].outcome = goOutput.Action
|
||||
pkgTests[testName].outcome = testOutcome(goOutput.Action)
|
||||
ch <- pkgTests[testName]
|
||||
case "output":
|
||||
if suffix, ok := strings.CutPrefix(strings.TrimSpace(goOutput.Output), flakytest.FlakyTestLogMessage); ok {
|
||||
@@ -372,6 +453,275 @@ func runTests(ctx context.Context, attempt int, pt *packageTests, goTestArgs, te
|
||||
return nil
|
||||
}
|
||||
|
||||
// runOneTest runs a single test in a single package via `go test -run` with a
|
||||
// per-attempt -timeout. It returns the test's outcome (outcomePass /
|
||||
// outcomeFail / outcomeSkip), the wall-clock time spent on this attempt
|
||||
// (used for the per-test retry budget), and any captured test logs.
|
||||
//
|
||||
// On panic, timeout, or any other failure mode where the test does not emit a
|
||||
// pass/fail/skip JSON event, outcome is reported as outcomeFail.
|
||||
func runOneTest(ctx context.Context, pkg, testName string, perAttemptTimeout time.Duration, attemptNum int, goTestArgs, testArgs []string) (outcome testOutcome, wallDur time.Duration, logs bytes.Buffer, err error) {
|
||||
goTestArgs, perAttemptTimeout = extractTimeout(goTestArgs, perAttemptTimeout)
|
||||
testArgs, perAttemptTimeout = extractTimeout(testArgs, perAttemptTimeout)
|
||||
args := []string{"test", "-json"}
|
||||
args = append(args, goTestArgs...)
|
||||
args = append(args, "-timeout", perAttemptTimeout.String())
|
||||
args = append(args, pkg)
|
||||
args = append(args, "--run", "^("+regexp.QuoteMeta(testName)+")$")
|
||||
args = append(args, testArgs...)
|
||||
|
||||
if debug {
|
||||
fmt.Println("running", strings.Join(args, " "))
|
||||
}
|
||||
cmd := exec.CommandContext(ctx, "go", args...)
|
||||
// Strip TS_TEST_SHARD so the child doesn't try to shard inside a
|
||||
// single-test retry — we are telling it exactly what to run.
|
||||
cmd.Env = slices.DeleteFunc(os.Environ(), func(s string) bool {
|
||||
return strings.HasPrefix(s, "TS_TEST_SHARD=")
|
||||
})
|
||||
cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", flakytest.FlakeAttemptEnv, attemptNum))
|
||||
r, perr := cmd.StdoutPipe()
|
||||
if perr != nil {
|
||||
return "", 0, logs, fmt.Errorf("stdout pipe: %w", perr)
|
||||
}
|
||||
defer r.Close()
|
||||
cmd.Stderr = os.Stderr
|
||||
|
||||
wallStart := time.Now()
|
||||
if err := cmd.Start(); err != nil {
|
||||
return "", 0, logs, fmt.Errorf("starting go test: %w", err)
|
||||
}
|
||||
|
||||
s := bufio.NewScanner(r)
|
||||
for s.Scan() {
|
||||
var ev goTestOutput
|
||||
if err := json.Unmarshal(s.Bytes(), &ev); err != nil {
|
||||
continue
|
||||
}
|
||||
if ev.Test == "" {
|
||||
continue // package-level events ignored for single-test runs
|
||||
}
|
||||
// Collapse subtests to parent.
|
||||
parent, _, _ := strings.Cut(ev.Test, "/")
|
||||
if parent != testName {
|
||||
continue
|
||||
}
|
||||
switch ev.Action {
|
||||
case "pass", "fail", "skip":
|
||||
if ev.Test == testName {
|
||||
outcome = testOutcome(ev.Action)
|
||||
}
|
||||
case "output":
|
||||
logs.WriteString(ev.Output)
|
||||
}
|
||||
}
|
||||
waitErr := cmd.Wait()
|
||||
wallDur = time.Since(wallStart)
|
||||
if scanErr := s.Err(); scanErr != nil && err == nil {
|
||||
err = fmt.Errorf("reading go test stdout: %w", scanErr)
|
||||
}
|
||||
if outcome == outcomeUnknown {
|
||||
// Test never emitted a pass/fail/skip — likely a panic, timeout, or
|
||||
// build error. Treat as fail.
|
||||
outcome = outcomeFail
|
||||
}
|
||||
if waitErr != nil && err == nil && outcome == outcomePass {
|
||||
// A non-zero exit when outcome==outcomePass is unexpected; surface it.
|
||||
err = waitErr
|
||||
}
|
||||
return outcome, wallDur, logs, err
|
||||
}
|
||||
|
||||
// extractTimeout returns args with any -timeout / -test.timeout flags
|
||||
// stripped, and the smaller of cap and the user-supplied timeout (if any).
|
||||
// This lets retries use the testwrapper-computed per-attempt timeout, but
|
||||
// never exceed an explicit -timeout the user passed on the command line.
|
||||
func extractTimeout(args []string, cap time.Duration) (stripped []string, t time.Duration) {
|
||||
t = cap
|
||||
stripped = make([]string, 0, len(args))
|
||||
for i := 0; i < len(args); i++ {
|
||||
a := args[i]
|
||||
bare := strings.TrimLeft(a, "-")
|
||||
name, val, hasEq := strings.Cut(bare, "=")
|
||||
if name == "timeout" || name == "test.timeout" {
|
||||
var raw string
|
||||
if hasEq {
|
||||
raw = val
|
||||
} else if i+1 < len(args) {
|
||||
raw = args[i+1]
|
||||
i++
|
||||
}
|
||||
if d, err := time.ParseDuration(raw); err == nil && d < t {
|
||||
t = d
|
||||
}
|
||||
continue
|
||||
}
|
||||
stripped = append(stripped, a)
|
||||
}
|
||||
return stripped, t
|
||||
}
|
||||
|
||||
// computePerAttemptTimeout returns the -timeout we use for each retry attempt
|
||||
// of a test that first failed in firstFail.
|
||||
//
|
||||
// It is the smaller of perAttemptCap (5 min) and 1.5*firstFail, but never
|
||||
// smaller than perAttemptFloor (30 s).
|
||||
func computePerAttemptTimeout(firstFail time.Duration) time.Duration {
|
||||
t := time.Duration(float64(firstFail) * 1.5)
|
||||
return max(perAttemptFloor, min(perAttemptCap, t))
|
||||
}
|
||||
|
||||
// retryFailedTest runs the per-test retry loop for ft. It updates ft in place.
|
||||
func retryFailedTest(ctx context.Context, ft *failedTest, goTestArgs, testArgs []string) {
|
||||
perAttempt := computePerAttemptTimeout(ft.firstFailDuration)
|
||||
for {
|
||||
if ft.everPassed {
|
||||
return
|
||||
}
|
||||
if ft.attempts >= maxRetries {
|
||||
return
|
||||
}
|
||||
if ft.attempts >= minRetries && ft.totalRetryElapsed >= perTestBudget {
|
||||
return
|
||||
}
|
||||
|
||||
// FlakeAttemptEnv is 1-indexed counting the first pass as attempt 1.
|
||||
// Retry attempt N is FlakeAttemptEnv = 1 + N.
|
||||
attemptNum := 1 + ft.attempts + 1
|
||||
outcome, dur, logs, err := runOneTest(ctx, ft.pkg, ft.testName, perAttempt, attemptNum, goTestArgs, testArgs)
|
||||
ft.attempts++
|
||||
ft.totalRetryElapsed += dur
|
||||
|
||||
fmt.Printf(" [retry %d] %s.%s: %s (%.3fs)\n",
|
||||
ft.attempts, ft.pkg, ft.testName, strings.ToUpper(string(outcome)), dur.Seconds())
|
||||
if err != nil {
|
||||
log.Printf("testwrapper: error running %s.%s: %v", ft.pkg, ft.testName, err)
|
||||
}
|
||||
if testingVerbose || outcome == outcomeFail {
|
||||
io.Copy(os.Stdout, &logs)
|
||||
}
|
||||
if outcome == outcomePass {
|
||||
ft.everPassed = true
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// detectRepo returns the GitHub "owner/repo" we're running in, used in the
|
||||
// fake issue URL recorded for unmarked flaky tests.
|
||||
//
|
||||
// It checks GITHUB_REPOSITORY (set by GitHub Actions), then `git config --get
|
||||
// remote.origin.url`, then falls back to "tailscale/tailscale".
|
||||
func detectRepo() string {
|
||||
if r := os.Getenv("GITHUB_REPOSITORY"); r != "" {
|
||||
return r
|
||||
}
|
||||
out, err := exec.Command("git", "config", "--get", "remote.origin.url").Output()
|
||||
if err == nil {
|
||||
if r := parseGitRemote(strings.TrimSpace(string(out))); r != "" {
|
||||
return r
|
||||
}
|
||||
}
|
||||
return "tailscale/tailscale"
|
||||
}
|
||||
|
||||
// parseGitRemote pulls "owner/repo" out of common git remote URL forms:
|
||||
// - git@github.com:owner/repo.git
|
||||
// - https://github.com/owner/repo.git
|
||||
// - https://github.com/owner/repo
|
||||
func parseGitRemote(url string) string {
|
||||
url = strings.TrimSuffix(url, ".git")
|
||||
// SSH form
|
||||
if rest, ok := strings.CutPrefix(url, "git@github.com:"); ok {
|
||||
return rest
|
||||
}
|
||||
// HTTPS form
|
||||
for _, p := range []string{"https://github.com/", "http://github.com/"} {
|
||||
if rest, ok := strings.CutPrefix(url, p); ok {
|
||||
return rest
|
||||
}
|
||||
}
|
||||
return ""
|
||||
}
|
||||
|
||||
// fakeIssueURL returns the fake GitHub issue URL we record for unmarked tests
|
||||
// that turn out to be flaky.
|
||||
func fakeIssueURL(repo string) string {
|
||||
return "https://github.com/" + repo + flakeUnknownIssueSlug
|
||||
}
|
||||
|
||||
// writeFlakeSummary appends a markdown summary of flaky tests to path,
|
||||
// creating it if needed. In practice path is the GitHub Actions runner's
|
||||
// $GITHUB_STEP_SUMMARY, which testwrapper auto-detects. It logs and
|
||||
// continues on errors, as a CI write failure should not poison the test
|
||||
// run's exit status.
|
||||
func writeFlakeSummary(path string, flaky []*failedTest, repo string) {
|
||||
f, err := os.OpenFile(path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644)
|
||||
if err != nil {
|
||||
log.Printf("testwrapper: opening summary file %s: %v", path, err)
|
||||
return
|
||||
}
|
||||
defer f.Close()
|
||||
if len(flaky) == 0 {
|
||||
fmt.Fprintln(f, "_No flaky tests detected._")
|
||||
return
|
||||
}
|
||||
fmt.Fprintln(f, "### Flaky tests detected")
|
||||
fmt.Fprintln(f)
|
||||
fmt.Fprintln(f, "Tests that failed at least once and then passed on retry. Rows tagged 🆕 were not annotated with flakytest.Mark; testwrapper auto-detected the flake.")
|
||||
fmt.Fprintln(f)
|
||||
fmt.Fprintln(f, "| Package | Test | Retries | Retry time | Issue |")
|
||||
fmt.Fprintln(f, "|---------|------|--------:|-----------:|-------|")
|
||||
for _, ft := range flaky {
|
||||
url := ft.issueURL
|
||||
if url == "" {
|
||||
url = fakeIssueURL(repo)
|
||||
}
|
||||
var tag string
|
||||
if ft.issueURL == "" {
|
||||
tag = " 🆕"
|
||||
}
|
||||
fmt.Fprintf(f, "| `%s` | `%s`%s | %d | %.1fs | [link](%s) |\n",
|
||||
ft.pkg, ft.testName, tag, ft.attempts, ft.totalRetryElapsed.Seconds(), url)
|
||||
}
|
||||
}
|
||||
|
||||
// buildPackageTests groups failedTests by package into the wire format
|
||||
// flakeapp expects.
|
||||
//
|
||||
// If fakeRepo is non-empty, tests with no real issue URL (i.e. not marked via
|
||||
// flakytest.Mark) get a fake URL of the form
|
||||
// https://github.com/{fakeRepo}/issues/UNKNOWN. If fakeRepo is empty, those
|
||||
// tests are simply omitted from the IssueURLs map.
|
||||
func buildPackageTests(fts []*failedTest, fakeRepo string) []packageTests {
|
||||
byPkg := map[string][]*failedTest{}
|
||||
for _, ft := range fts {
|
||||
byPkg[ft.pkg] = append(byPkg[ft.pkg], ft)
|
||||
}
|
||||
pkgs := make([]string, 0, len(byPkg))
|
||||
for p := range byPkg {
|
||||
pkgs = append(pkgs, p)
|
||||
}
|
||||
sort.Strings(pkgs)
|
||||
out := make([]packageTests, 0, len(pkgs))
|
||||
for _, p := range pkgs {
|
||||
group := byPkg[p]
|
||||
slices.SortFunc(group, func(a, b *failedTest) int { return strings.Compare(a.testName, b.testName) })
|
||||
pt := packageTests{Pattern: p, IssueURLs: map[string]string{}}
|
||||
for _, ft := range group {
|
||||
pt.Tests = append(pt.Tests, ft.testName)
|
||||
url := ft.issueURL
|
||||
if url == "" && fakeRepo != "" {
|
||||
url = fakeIssueURL(fakeRepo)
|
||||
}
|
||||
if url != "" {
|
||||
pt.IssueURLs[ft.testName] = url
|
||||
}
|
||||
}
|
||||
out = append(out, pt)
|
||||
}
|
||||
return out
|
||||
}
|
||||
|
||||
func main() {
|
||||
goTestArgs, packages, testArgs, err := splitArgs(os.Args[1:])
|
||||
if err != nil {
|
||||
@@ -394,34 +744,22 @@ func main() {
|
||||
}
|
||||
|
||||
ctx := context.Background()
|
||||
type nextRun struct {
|
||||
tests []*packageTests
|
||||
attempt int // starting at 1
|
||||
}
|
||||
firstRun := &nextRun{
|
||||
attempt: 1,
|
||||
}
|
||||
for _, pkg := range packages {
|
||||
firstRun.tests = append(firstRun.tests, &packageTests{Pattern: pkg})
|
||||
}
|
||||
toRun := []*nextRun{firstRun}
|
||||
printPkgOutcome := func(pkg, outcome string, cached bool, attempt int, testDur time.Duration) {
|
||||
repo := detectRepo()
|
||||
|
||||
printPkgOutcome := func(pkg string, outcome testOutcome, cached bool, testDur time.Duration) {
|
||||
if pkg == "" {
|
||||
return // We reach this path on a build error.
|
||||
}
|
||||
if outcome == "skip" {
|
||||
if outcome == outcomeSkip {
|
||||
fmt.Printf("?\t%s [skipped/no tests] \n", pkg)
|
||||
return
|
||||
}
|
||||
if outcome == "pass" {
|
||||
outcome = "ok"
|
||||
label := string(outcome)
|
||||
if outcome == outcomePass {
|
||||
label = "ok"
|
||||
}
|
||||
if outcome == "fail" {
|
||||
outcome = "FAIL"
|
||||
}
|
||||
if attempt > 1 {
|
||||
fmt.Printf("%s\t%s\t%.3fs\t[attempt=%d]\n", outcome, pkg, testDur.Seconds(), attempt)
|
||||
return
|
||||
if outcome == outcomeFail {
|
||||
label = "FAIL"
|
||||
}
|
||||
var lastCol string
|
||||
if cached {
|
||||
@@ -429,131 +767,112 @@ func main() {
|
||||
} else {
|
||||
lastCol = fmt.Sprintf("%.3fs", testDur.Seconds())
|
||||
}
|
||||
fmt.Printf("%s\t%s\t%v\n", outcome, pkg, lastCol)
|
||||
fmt.Printf("%s\t%s\t%v\n", label, pkg, lastCol)
|
||||
}
|
||||
|
||||
for len(toRun) > 0 {
|
||||
var thisRun *nextRun
|
||||
thisRun, toRun = toRun[0], toRun[1:]
|
||||
// First pass: run every package once, collect failed tests for retry.
|
||||
var failed []*failedTest
|
||||
var pkgFatal bool // a package produced a non-test fatal (build error, etc.)
|
||||
for _, pkgPattern := range packages {
|
||||
pt := &packageTests{Pattern: pkgPattern}
|
||||
ch := make(chan *testAttempt)
|
||||
runErrCh := make(chan error, 1)
|
||||
go func() {
|
||||
defer close(runErrCh)
|
||||
runErrCh <- runTests(ctx, 1, pt, goTestArgs, testArgs, ch)
|
||||
}()
|
||||
|
||||
if thisRun.attempt > maxAttempts {
|
||||
fmt.Println("max attempts reached")
|
||||
os.Exit(1)
|
||||
}
|
||||
if thisRun.attempt > 1 {
|
||||
j, _ := json.Marshal(thisRun.tests)
|
||||
fmt.Printf("\n\nAttempt #%d: Retrying flaky tests:\n\nflakytest failures JSON: %s\n\n", thisRun.attempt, j)
|
||||
}
|
||||
|
||||
fatalFailures := make(map[string]struct{}) // pkg.Test key
|
||||
toRetry := make(map[string][]*testAttempt) // pkg -> tests to retry
|
||||
for _, pt := range thisRun.tests {
|
||||
ch := make(chan *testAttempt)
|
||||
runErr := make(chan error, 1)
|
||||
go func() {
|
||||
defer close(runErr)
|
||||
runErr <- runTests(ctx, thisRun.attempt, pt, goTestArgs, testArgs, ch)
|
||||
}()
|
||||
|
||||
var failed bool
|
||||
for tr := range ch {
|
||||
// Go assigns the package name "command-line-arguments" when you
|
||||
// `go test FILE` rather than `go test PKG`. It's more
|
||||
// convenient for us to to specify files in tests, so fix tr.pkg
|
||||
// so that subsequent testwrapper attempts run correctly.
|
||||
if tr.pkg == "command-line-arguments" {
|
||||
tr.pkg = packages[0]
|
||||
// Collect failed tests in this package on the side; we use the count
|
||||
// when a package reports a fail to decide if the failure is explained
|
||||
// by retryable test failures or is a separate package-level fatal.
|
||||
var pkgFailedTests []*failedTest
|
||||
for tr := range ch {
|
||||
// Go assigns the package name "command-line-arguments" when you
|
||||
// `go test FILE` rather than `go test PKG`. It's more
|
||||
// convenient for us to to specify files in tests, so fix tr.pkg
|
||||
// so that subsequent testwrapper attempts run correctly.
|
||||
if tr.pkg == "command-line-arguments" {
|
||||
tr.pkg = packages[0]
|
||||
}
|
||||
if tr.pkgFinished {
|
||||
if tr.raceDetected {
|
||||
// A data race is never something we want to paper
|
||||
// over by retrying flaky tests in the package: the
|
||||
// race indicates a real bug that may not even be
|
||||
// in the failing test, and a retry could hide it.
|
||||
// Drop any retry plans for this pkg and fail fast.
|
||||
pkgFailedTests = nil
|
||||
pkgFatal = true
|
||||
}
|
||||
if tr.pkgFinished {
|
||||
if tr.raceDetected {
|
||||
// A data race is never something we want to
|
||||
// paper over by retrying flaky tests in the
|
||||
// package: the race indicates a real bug
|
||||
// that may not even be in the failing test,
|
||||
// and a retry could hide it. Discard any
|
||||
// retry plans for this pkg and fail fast.
|
||||
delete(toRetry, tr.pkg)
|
||||
failed = true
|
||||
}
|
||||
if tr.outcome == "fail" && len(toRetry[tr.pkg]) == 0 {
|
||||
// If a package fails and we don't have any tests to
|
||||
// retry, then we should fail. This typically happens
|
||||
// when a package times out.
|
||||
failed = true
|
||||
}
|
||||
if testingVerbose || tr.outcome == "fail" {
|
||||
// Output package-level output which is where e.g.
|
||||
// panics outside tests will be printed
|
||||
io.Copy(os.Stdout, &tr.logs)
|
||||
}
|
||||
printPkgOutcome(tr.pkg, tr.outcome, tr.cached, thisRun.attempt, tr.end.Sub(tr.start))
|
||||
continue
|
||||
}
|
||||
if testingVerbose || tr.outcome == "fail" {
|
||||
if testingVerbose || tr.outcome == outcomeFail {
|
||||
io.Copy(os.Stdout, &tr.logs)
|
||||
}
|
||||
if tr.outcome != "fail" {
|
||||
continue
|
||||
}
|
||||
if tr.isMarkedFlaky {
|
||||
toRetry[tr.pkg] = append(toRetry[tr.pkg], tr)
|
||||
} else {
|
||||
fatalFailures[tr.pkg+"."+tr.testName] = struct{}{}
|
||||
failed = true
|
||||
if tr.outcome == outcomeFail && len(pkgFailedTests) == 0 {
|
||||
// Package failed but no test failed (e.g. the package
|
||||
// timed out, or a build error). Not retryable per-test.
|
||||
pkgFatal = true
|
||||
}
|
||||
printPkgOutcome(tr.pkg, tr.outcome, tr.cached, tr.end.Sub(tr.start))
|
||||
continue
|
||||
}
|
||||
if failed {
|
||||
fmt.Println("\n\nNot retrying flaky tests because non-flaky tests failed.")
|
||||
|
||||
// Print the list of non-flakytest failures.
|
||||
// We will later analyze the retried GitHub Action runs to see
|
||||
// if non-flakytest failures succeeded upon retry. This will
|
||||
// highlight tests which are flaky but not yet flagged as such.
|
||||
if len(fatalFailures) > 0 {
|
||||
tests := slicesx.MapKeys(fatalFailures)
|
||||
sort.Strings(tests)
|
||||
j, _ := json.Marshal(tests)
|
||||
fmt.Printf("non-flakytest failures: %s\n", j)
|
||||
}
|
||||
fmt.Println()
|
||||
os.Exit(1)
|
||||
if testingVerbose || tr.outcome == outcomeFail {
|
||||
io.Copy(os.Stdout, &tr.logs)
|
||||
}
|
||||
|
||||
// If there's nothing to retry and no non-retryable tests have
|
||||
// failed then we've probably hit a build error.
|
||||
if err := <-runErr; len(toRetry) == 0 && err != nil {
|
||||
if exit, ok := errors.AsType[*exec.ExitError](err); ok {
|
||||
if code := exit.ExitCode(); code > -1 {
|
||||
os.Exit(exit.ExitCode())
|
||||
}
|
||||
}
|
||||
log.Printf("testwrapper: %s", err)
|
||||
os.Exit(1)
|
||||
if tr.outcome != outcomeFail {
|
||||
continue
|
||||
}
|
||||
}
|
||||
if len(toRetry) == 0 {
|
||||
continue
|
||||
}
|
||||
pkgs := slicesx.MapKeys(toRetry)
|
||||
sort.Strings(pkgs)
|
||||
nextRun := &nextRun{
|
||||
attempt: thisRun.attempt + 1,
|
||||
}
|
||||
for _, pkg := range pkgs {
|
||||
tests := toRetry[pkg]
|
||||
slices.SortFunc(tests, func(a, b *testAttempt) int { return strings.Compare(a.testName, b.testName) })
|
||||
issueURLs := map[string]string{} // test name => URL
|
||||
var testNames []string
|
||||
for _, ta := range tests {
|
||||
issueURLs[ta.testName] = ta.issueURL
|
||||
testNames = append(testNames, ta.testName)
|
||||
}
|
||||
nextRun.tests = append(nextRun.tests, &packageTests{
|
||||
Pattern: pkg,
|
||||
Tests: testNames,
|
||||
IssueURLs: issueURLs,
|
||||
pkgFailedTests = append(pkgFailedTests, &failedTest{
|
||||
pkg: tr.pkg,
|
||||
testName: tr.testName,
|
||||
firstFailDuration: tr.end.Sub(tr.start),
|
||||
issueURL: tr.issueURL, // real if Mark()'d, else "".
|
||||
})
|
||||
}
|
||||
toRun = append(toRun, nextRun)
|
||||
failed = append(failed, pkgFailedTests...)
|
||||
if err := <-runErrCh; err != nil {
|
||||
if exit, ok := errors.AsType[*exec.ExitError](err); ok {
|
||||
if code := exit.ExitCode(); code > -1 && len(pkgFailedTests) == 0 {
|
||||
// Pure exec failure with no test-level failures to retry:
|
||||
// honor the original exit code.
|
||||
os.Exit(code)
|
||||
}
|
||||
} else {
|
||||
log.Printf("testwrapper: %s", err)
|
||||
pkgFatal = true
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// Second pass: retry each failed test serially with its per-test budget.
|
||||
if len(failed) > 0 {
|
||||
fmt.Printf("\n\nRetrying %d failed test(s) to detect flakiness...\n\n", len(failed))
|
||||
for _, ft := range failed {
|
||||
retryFailedTest(ctx, ft, goTestArgs, testArgs)
|
||||
}
|
||||
}
|
||||
|
||||
// Summarize and exit.
|
||||
var flaky, permanent []*failedTest
|
||||
for _, ft := range failed {
|
||||
if ft.everPassed {
|
||||
flaky = append(flaky, ft)
|
||||
} else {
|
||||
permanent = append(permanent, ft)
|
||||
}
|
||||
}
|
||||
if len(flaky) > 0 {
|
||||
j, _ := json.Marshal(buildPackageTests(flaky, repo))
|
||||
fmt.Printf("\nflakytest failures JSON: %s\n", j)
|
||||
}
|
||||
if path := os.Getenv("GITHUB_STEP_SUMMARY"); path != "" {
|
||||
writeFlakeSummary(path, flaky, repo)
|
||||
}
|
||||
if len(permanent) > 0 {
|
||||
j, _ := json.Marshal(buildPackageTests(permanent, ""))
|
||||
fmt.Printf("\npermanent test failures JSON: %s\n", j)
|
||||
}
|
||||
|
||||
if pkgFatal || len(permanent) > 0 {
|
||||
os.Exit(1)
|
||||
}
|
||||
}
|
||||
|
||||
@@ -10,7 +10,6 @@ import (
|
||||
"os"
|
||||
"os/exec"
|
||||
"path/filepath"
|
||||
"regexp"
|
||||
"runtime"
|
||||
"strings"
|
||||
"sync"
|
||||
@@ -30,7 +29,15 @@ func cmdTestwrapper(t *testing.T, args ...string) *exec.Cmd {
|
||||
if buildErr != nil {
|
||||
t.Fatalf("building testwrapper: %s", buildErr)
|
||||
}
|
||||
return exec.Command(buildPath, args...)
|
||||
cmd := exec.Command(buildPath, args...)
|
||||
// Tests of testwrapper run with a small per-test budget so they don't
|
||||
// take 10 minutes when checking permanent-failure behavior.
|
||||
cmd.Env = append(os.Environ(),
|
||||
"TS_TESTWRAPPER_BUDGET=2s",
|
||||
"TS_TESTWRAPPER_MIN_RETRIES=2",
|
||||
"GITHUB_REPOSITORY=tailscale/tailscale",
|
||||
)
|
||||
return cmd
|
||||
}
|
||||
|
||||
func buildTestWrapper() (string, error) {
|
||||
@@ -45,6 +52,9 @@ func buildTestWrapper() (string, error) {
|
||||
return filepath.Join(dir, "testwrapper"), nil
|
||||
}
|
||||
|
||||
// TestRetry covers a Mark()'d test that fails on the first attempt and passes
|
||||
// on retry: the wrapper must exit 0, emit a flakytest failures JSON line with
|
||||
// the real issue URL, and have run TestFlakeRun twice.
|
||||
func TestRetry(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
@@ -60,7 +70,7 @@ import (
|
||||
func TestOK(t *testing.T) {}
|
||||
|
||||
func TestFlakeRun(t *testing.T) {
|
||||
flakytest.Mark(t, "https://github.com/tailscale/tailscale/issues/0") // random issue
|
||||
flakytest.Mark(t, "https://github.com/tailscale/tailscale/issues/1234")
|
||||
e := os.Getenv(flakytest.FlakeAttemptEnv)
|
||||
if e == "" {
|
||||
t.Skip("not running in testwrapper")
|
||||
@@ -79,19 +89,20 @@ func TestFlakeRun(t *testing.T) {
|
||||
t.Fatalf("go run . %s: %s with output:\n%s", testfile, err, out)
|
||||
}
|
||||
|
||||
// Replace the unpredictable timestamp with "0.00s".
|
||||
out = regexp.MustCompile(`\t\d+\.\d\d\ds\t`).ReplaceAll(out, []byte("\t0.00s\t"))
|
||||
|
||||
want := []byte("ok\t" + testfile + "\t0.00s\t[attempt=2]")
|
||||
if !bytes.Contains(out, want) {
|
||||
t.Fatalf("wanted output containing %q but got:\n%s", want, out)
|
||||
if !bytes.Contains(out, []byte("flakytest failures JSON:")) {
|
||||
t.Errorf("missing flakytest failures JSON line in output:\n%s", out)
|
||||
}
|
||||
if !bytes.Contains(out, []byte("https://github.com/tailscale/tailscale/issues/1234")) {
|
||||
t.Errorf("missing real issue URL in output:\n%s", out)
|
||||
}
|
||||
if bytes.Contains(out, []byte("permanent test failures JSON:")) {
|
||||
t.Errorf("unexpected permanent failures line in output:\n%s", out)
|
||||
}
|
||||
|
||||
if okRuns := bytes.Count(out, []byte("=== RUN TestOK")); okRuns != 1 {
|
||||
t.Fatalf("expected TestOK to be run once but was run %d times in output:\n%s", okRuns, out)
|
||||
t.Errorf("expected TestOK to be run once but was run %d times in output:\n%s", okRuns, out)
|
||||
}
|
||||
if flakeRuns := bytes.Count(out, []byte("=== RUN TestFlakeRun")); flakeRuns != 2 {
|
||||
t.Fatalf("expected TestFlakeRun to be run twice but was run %d times in output:\n%s", flakeRuns, out)
|
||||
t.Errorf("expected TestFlakeRun to be run twice but was run %d times in output:\n%s", flakeRuns, out)
|
||||
}
|
||||
|
||||
if testing.Verbose() {
|
||||
@@ -99,45 +110,97 @@ func TestFlakeRun(t *testing.T) {
|
||||
}
|
||||
}
|
||||
|
||||
func TestNoRetry(t *testing.T) {
|
||||
// TestAutoRetry covers a non-Mark()'d test that fails on the first attempt and
|
||||
// passes on retry: the wrapper must exit 0, emit a flakytest failures JSON
|
||||
// line with a fake /issues/UNKNOWN URL, and have run the test twice.
|
||||
func TestAutoRetry(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
testfile := filepath.Join(t.TempDir(), "noretry_test.go")
|
||||
code := []byte(`package noretry_test
|
||||
testfile := filepath.Join(t.TempDir(), "autoretry_test.go")
|
||||
// Note: no flakytest.Mark call. The wrapper should retry anyway.
|
||||
code := []byte(`package autoretry_test
|
||||
|
||||
import (
|
||||
"os"
|
||||
"testing"
|
||||
"tailscale.com/cmd/testwrapper/flakytest"
|
||||
)
|
||||
|
||||
func TestFlakeRun(t *testing.T) {
|
||||
flakytest.Mark(t, "https://github.com/tailscale/tailscale/issues/0") // random issue
|
||||
t.Error("shouldn't be retried")
|
||||
}
|
||||
|
||||
func TestAlwaysError(t *testing.T) {
|
||||
t.Error("error")
|
||||
func TestAutoFlake(t *testing.T) {
|
||||
e := os.Getenv("TS_TESTWRAPPER_ATTEMPT")
|
||||
if e == "" {
|
||||
t.Skip("not running in testwrapper")
|
||||
}
|
||||
if e == "1" {
|
||||
t.Fatal("First run in testwrapper, failing so that test is retried. This is expected.")
|
||||
}
|
||||
}
|
||||
`)
|
||||
if err := os.WriteFile(testfile, code, 0o644); err != nil {
|
||||
t.Fatalf("writing package: %s", err)
|
||||
}
|
||||
|
||||
out, err := cmdTestwrapper(t, "-v", testfile).Output()
|
||||
out, err := cmdTestwrapper(t, "-v", testfile).CombinedOutput()
|
||||
if err != nil {
|
||||
t.Fatalf("testwrapper %s: %s with output:\n%s", testfile, err, out)
|
||||
}
|
||||
|
||||
if !bytes.Contains(out, []byte("flakytest failures JSON:")) {
|
||||
t.Errorf("missing flakytest failures JSON line in output:\n%s", out)
|
||||
}
|
||||
if !bytes.Contains(out, []byte("/issues/UNKNOWN")) {
|
||||
t.Errorf("missing fake /issues/UNKNOWN URL in output:\n%s", out)
|
||||
}
|
||||
if !bytes.Contains(out, []byte("https://github.com/tailscale/tailscale/issues/UNKNOWN")) {
|
||||
t.Errorf("missing fake URL with detected repo in output:\n%s", out)
|
||||
}
|
||||
if bytes.Contains(out, []byte("permanent test failures JSON:")) {
|
||||
t.Errorf("unexpected permanent failures line in output:\n%s", out)
|
||||
}
|
||||
if runs := bytes.Count(out, []byte("=== RUN TestAutoFlake")); runs != 2 {
|
||||
t.Errorf("expected TestAutoFlake to run twice but ran %d times in output:\n%s", runs, out)
|
||||
}
|
||||
|
||||
if testing.Verbose() {
|
||||
t.Logf("success - output:\n%s", out)
|
||||
}
|
||||
}
|
||||
|
||||
// TestPermanentFailure covers a test that always fails: the wrapper must exit
|
||||
// non-zero, emit a permanent test failures JSON line, and NOT emit a flakytest
|
||||
// failures JSON line. The test should be retried at least minRetries times.
|
||||
func TestPermanentFailure(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
testfile := filepath.Join(t.TempDir(), "permfail_test.go")
|
||||
code := []byte(`package permfail_test
|
||||
|
||||
import "testing"
|
||||
|
||||
func TestAlwaysFail(t *testing.T) {
|
||||
t.Fatal("always fails")
|
||||
}
|
||||
`)
|
||||
if err := os.WriteFile(testfile, code, 0o644); err != nil {
|
||||
t.Fatalf("writing package: %s", err)
|
||||
}
|
||||
|
||||
out, err := cmdTestwrapper(t, "-v", testfile).CombinedOutput()
|
||||
if err == nil {
|
||||
t.Fatalf("go run . %s: expected error but it succeeded with output:\n%s", testfile, out)
|
||||
t.Fatalf("testwrapper %s: expected error but it succeeded with output:\n%s", testfile, out)
|
||||
}
|
||||
if code, ok := errExitCode(err); ok && code != 1 {
|
||||
t.Fatalf("expected exit code 1 but got %d", code)
|
||||
t.Errorf("expected exit code 1 but got %d; output:\n%s", code, out)
|
||||
}
|
||||
|
||||
want := []byte("Not retrying flaky tests because non-flaky tests failed.")
|
||||
if !bytes.Contains(out, want) {
|
||||
t.Fatalf("wanted output containing %q but got:\n%s", want, out)
|
||||
if bytes.Contains(out, []byte("flakytest failures JSON:")) {
|
||||
t.Errorf("unexpected flakytest failures JSON line in output (test never passed):\n%s", out)
|
||||
}
|
||||
|
||||
if flakeRuns := bytes.Count(out, []byte("=== RUN TestFlakeRun")); flakeRuns != 1 {
|
||||
t.Fatalf("expected TestFlakeRun to be run once but was run %d times in output:\n%s", flakeRuns, out)
|
||||
if !bytes.Contains(out, []byte("permanent test failures JSON:")) {
|
||||
t.Errorf("missing permanent test failures JSON line in output:\n%s", out)
|
||||
}
|
||||
// First pass + at least minRetries retries = 3 runs.
|
||||
if runs := bytes.Count(out, []byte("=== RUN TestAlwaysFail")); runs < 3 {
|
||||
t.Errorf("expected TestAlwaysFail to run >= 3 times (1 first + 2 retries) but ran %d times in output:\n%s", runs, out)
|
||||
}
|
||||
|
||||
if testing.Verbose() {
|
||||
@@ -191,10 +254,10 @@ func TestFlaky(t *testing.T) {
|
||||
if want := "WARNING: DATA RACE"; !bytes.Contains(out, []byte(want)) {
|
||||
t.Fatalf("expected race report in output, got:\n%s", out)
|
||||
}
|
||||
if want := "Not retrying flaky tests"; !bytes.Contains(out, []byte(want)) {
|
||||
t.Fatalf("expected no-retry message in output, got:\n%s", out)
|
||||
if bytes.Contains(out, []byte("Retrying")) {
|
||||
t.Fatalf("expected no retry phase in output, but found one:\n%s", out)
|
||||
}
|
||||
if got := bytes.Count(out, []byte("Attempt #")); got != 0 {
|
||||
if got := bytes.Count(out, []byte("[retry ")); got != 0 {
|
||||
t.Fatalf("expected no retry attempts to be made, but %d were:\n%s", got, out)
|
||||
}
|
||||
if got := bytes.Count(out, []byte("=== RUN TestFlaky")); got != 1 {
|
||||
@@ -316,10 +379,10 @@ func TestTimeout(t *testing.T) {
|
||||
|
||||
out, err := cmdTestwrapper(t, testfile, "-timeout=20ms").CombinedOutput()
|
||||
if code, ok := errExitCode(err); !ok || code != 1 {
|
||||
t.Fatalf("testwrapper %s: expected error with exit code 0 but got: %v; output was:\n%s", testfile, err, out)
|
||||
t.Fatalf("testwrapper %s: expected error with exit code 1 but got: %v; output was:\n%s", testfile, err, out)
|
||||
}
|
||||
if want := "panic: test timed out after 20ms"; !bytes.Contains(out, []byte(want)) {
|
||||
t.Fatalf("testwrapper %s: expected build error containing %q but got:\n%s", testfile, buildErr, out)
|
||||
t.Fatalf("testwrapper %s: expected timeout panic containing %q but got:\n%s", testfile, want, out)
|
||||
}
|
||||
|
||||
if testing.Verbose() {
|
||||
|
||||
Reference in New Issue
Block a user