From 1e0c50ad16dc2fcf68a210a521069c5bcf53fc0b Mon Sep 17 00:00:00 2001 From: DonislawDev Date: Tue, 3 Nov 2026 18:46:24 +0100 Subject: [PATCH 1/2] ci: the race job lays its guards out by what each weighs The steps added in #215 named the processor of every race part. The same part 2 took 1202 s on an AMD EPYC 7763, past its twenty minute timeout, and 689 s on an EPYC 9V45, every test of it slower by the same factor, while part 3 took 525 and 530 s on two 7763s. Split by the checksum of each name, the four parts were about 1250, 1158, 795 and 526 s on the 7763. .github/race-weights holds the 48 guards that took 10 s or more, each at the longest time any of eight parts took, and the mean of the rest. .github/scripts/race_parts.py lays those out heaviest first, each into the lightest part, over the light guards, which stay on the checksum so adding one moves no other. By the measured times the parts are now 912 to 961 s on the slowest processor. A weight for a test the binary does not list fails every part, and a test missing from the weights that runs 60 s or more fails its part with the line to add. The race job now also runs when either file changes. Five guards in raceparts_test.go: every guard in exactly one part, checked against the binary's own -test.list; the parts within a tenth of their mean and under 85% of the timeout read from ci.yml; the refusals; the unlisted check; and the job's use of both. Thirteen mutation entries. Co-Authored-By: Claude Opus 5.5 --- .github/race-weights | 63 ++++++ .github/scripts/race_parts.py | 147 ++++++++++++++ .github/workflows/ci.yml | 57 +++--- internal/guard/mutation/entries.py | 93 +++++++++ internal/guard/raceparts_test.go | 306 +++++++++++++++++++++++++++++ 5 files changed, 638 insertions(+), 28 deletions(-) create mode 100644 .github/race-weights create mode 100644 .github/scripts/race_parts.py create mode 100644 internal/guard/raceparts_test.go diff --git a/.github/race-weights b/.github/race-weights new file mode 100644 index 00000000..8bb69854 --- /dev/null +++ b/.github/race-weights @@ -0,0 +1,63 @@ +# What each guard weighs in the race job of ci.yml, in seconds under the race +# detector. .github/scripts/race_parts.py lays these out over the parts, the +# heaviest first, and sends every test not named here by the checksum of its +# name, counted at the "unlisted" weight. +# +# Taken on 2026-11-03 from eight parts of two runs, each test at the longest +# time any of them took. The race job runs on whatever processor the runner +# is given, and the same part took 689 s on one and 1202 s on another, every +# test of it slower by the same factor. The longest time is the slowest +# processor's, so the parts are even where they are closest to the timeout. +# Listed: every test that took 10 s or more. "unlisted" is the mean of the rest. +# +# A test that is not here and takes 60 s or more fails its part with the line +# to add. A test that is here and no longer exists fails every part. +unlisted 0.58 +348.3 TestAFormatRefusesASizeItCannotDescribe +343.3 TestAFilmStoppedHalfWayLeavesNoHelperRunning +329.9 TestEveryFormatHitsTheOrderedSizeExactly +162.6 TestEveryScreenStillDrawsItsStoredPicture +155.5 TestACompressedZipIsEitherWrittenAtItsSizeOrRefusedInWords +142.2 TestEveryTileOfAFilmIsGav1dsCodingOfItsPixelsAndDecodesAsItDoesAlone +130.0 TestTheMinimumThisToolPrintsStandsWhateverTheSeedIs +117.9 TestFreeBoxesCarryPaddingOfAnyLength +99.9 TestEveryBase64TextSizeIsExact +93.8 TestAFilmPictureLargerThanAnyAV1LevelIsRefusedNotBroken +67.9 TestADeclaredDefaultIsTheOneTheFormatUses +64.3 TestNoTrackedFileCarriesPrivateContent +63.8 TestNoGeneratorHoldsTheWholeFileInMemory +57.3 TestAFilmSaysItCarriesItsLabelOnlyWhenAPictureShowsItWhole +55.3 TestAFilmOfANamedSizeKeepsEveryPictureInsideItsReserve +53.4 TestTheArchiveScanLooksIntoTheArchivesInside +38.5 TestAContainerStopsBetweenTheFilesItPlans +37.5 TestEveryPictureNamedAfterARefusalShowsOne +36.7 TestTheArchiveScanReadsTheListArchiveZipReads +35.9 TestTheArchiveScanFindsEveryTrapItNames +35.5 TestJxlStillFitsWhenTheQualityIsNotTheOneTheCeilingsWereMeasuredAt +30.8 TestOurOwnGeneratorsHaveNotDrifted +29.9 TestTheSameSeedGivesTheSameBytes +27.7 TestTheCeilingCountsTheWholeRunNotOneTarget +26.8 TestEveryJxlRungStillFitsInsideItsDeclaredCeiling +26.6 TestTheMinimumStandsWhateverTheSeedIsUnderEveryDeclaredChoice +24.9 TestEveryEMLSettingSurvivesItsReferenceTool +24.2 TestEveryLinkOnTheSiteLeadsSomewhere +24.2 TestAPictureSaysItCarriesItsLabelOnlyWhenItsTextIsWhole +20.9 TestAFilmsProgressMovesWithItsPicturesNotItsPadding +20.7 TestAFilmHoldsTheFramesTheManifestDeclares +20.7 TestTheWindowBinaryStartsWithoutAConsole +19.9 TestAFilmWhoseSquareCoversItsLabelSaysSoInItsPlan +19.9 TestTheSiteSaysWhatTheToolSays +19.8 TestChoosingAToolLaysTheScreenOutAsIfItOpenedWithIt +19.8 TestTheArchiveScanHoldsNoMoreOfANameThanTheName +16.6 TestEveryLanguageDescribesEveryDamage +16.3 TestTheSameWorkDoneAgainLeavesTheWindowAsItWas +16.2 TestABuildWithNoWindowInItSaysSoAndKeepsStandardOutputEmpty +16.0 TestEveryLanguageDescribesEverythingTheProgramCanProduce +15.4 TestAvifStillFitsWhenTheQualityIsNotTheOneTheCeilingsWereMeasuredAt +15.2 TestAFinishedRunInTheWindowSaysItsManifestIsTooBigToReadBack +15.1 TestABuildWithoutTheBuildTagsRefusesAndSaysWhy +14.9 TestAShortcutCannotStartASecondRunDuringTheFirst +14.6 TestTheLicenceCommandListsWhatTheBinaryLinks +14.4 TestEveryFormatSurvivesItsReferenceTool +12.2 TestTheMemoryFlagReachesThePlanOnEveryCommandThatPlans +11.2 TestTheCommandLineHoldsTheWholeRunToItsMemorySetting diff --git a/.github/scripts/race_parts.py b/.github/scripts/race_parts.py new file mode 100644 index 00000000..d6757c2a --- /dev/null +++ b/.github/scripts/race_parts.py @@ -0,0 +1,147 @@ +"""Which guards one part of the race job runs, and whether the weights still hold. + + race_parts.py split NAMES WEIGHTS PART PARTS > mine.txt + race_parts.py unlisted WEIGHTS LOG + +split prints the names of NAMES (one per line, as go test -list gives them) +that part PART of PARTS runs. The tests WEIGHTS names are laid out by their +weight, the heaviest first, each into the part that is lightest so far. Every +other test goes where the checksum of its name sends it and counts as the +"unlisted" weight, so adding or removing a light test moves no other test, and +the heavy ones are laid over the light ones rather than beside them. + +unlisted reads the log of a part (go test -v) and fails when a test WEIGHTS +does not name took UNLISTED_CEILING seconds or more. Such a test is laid out as +if it were light, and the parts stop being even without anything saying so. + +Both fail closed, with a sentence that names what to change: a weight for a +test the binary does not list (renamed or removed), a line that is not a +weight, a name given twice, no "unlisted" line, or a part outside the parts. +""" + +import math +import re +import sys +import zlib + +# The weights list every test that took 10 s or more on the slowest processor +# measured, so an unlisted test is under 10 s there, and no test measured took +# more than 2.7 times as long on one processor as on another. Six times the +# listing threshold is a test that is new or has grown, not one the machine +# made slow. +UNLISTED_CEILING = 60.0 + +TOP = re.compile(r"^--- (?:PASS|FAIL|SKIP): (\S+) \(([0-9.]+)s\)$") + + +def refuse(message): + print(message, file=sys.stderr) + sys.exit(1) + + +def read_lines(path, what): + try: + with open(path, encoding="utf-8") as f: + return f.read().splitlines() + except (OSError, UnicodeDecodeError) as err: + refuse("cannot read the %s %s: %s" % (what, path, err)) + + +def read_weights(path): + unlisted = None + weights = {} + for number, line in enumerate(read_lines(path, "weights"), 1): + text = line.strip() + if not text or text.startswith("#"): + continue + fields = text.split() + where = "%s line %d (%s)" % (path, number, text) + if len(fields) != 2: + refuse("%s is not a weight. Each line is seconds and a test name, or \"unlisted\" and seconds." % where) + if fields[0] == "unlisted": + if unlisted is not None: + refuse("%s gives the unlisted weight a second time." % where) + unlisted = seconds(fields[1], where) + continue + took, name = seconds(fields[0], where), fields[1] + if name in weights: + refuse("%s names %s a second time. Keep one line for it." % (where, name)) + weights[name] = took + if unlisted is None: + refuse("%s has no \"unlisted\" line, so the tests it does not name weigh nothing. " + "Add one with the mean time of those tests." % path) + return unlisted, weights + + +def seconds(text, where): + try: + value = float(text) + except ValueError: + value = math.nan + if not math.isfinite(value) or value < 0: + refuse("%s gives %s, and a weight is a number of seconds, nought or more." % (where, text)) + return value + + +def lay_out(names, unlisted, weights, parts): + """Return the part of every name and the weight each part carries.""" + gone = [name for name in weights if name not in names] + if gone: + refuse("the weights name %s, which the test binary does not list - a test renamed or removed. " + "Take the line out of the weights, or give it the test's new name." % ", ".join(sorted(gone))) + part_of = {} + load = [0.0] * parts + for name in names: + if name not in weights: + part = zlib.crc32(name.encode("utf-8")) % parts + part_of[name] = part + load[part] += unlisted + for name in sorted(weights, key=lambda n: (-weights[n], n)): + part = min(range(parts), key=lambda p: (load[p], p)) + part_of[name] = part + load[part] += weights[name] + return part_of, load + + +def split(names_path, weights_path, part_text, parts_text): + try: + part, parts = int(part_text), int(parts_text) + except ValueError: + refuse("the part and the number of parts are whole numbers, and these are %s and %s." % (part_text, parts_text)) + if parts < 1 or not 0 <= part < parts: + refuse("part %d of %d does not exist. Parts count from nought and stay below their number." % (part, parts)) + names = list(dict.fromkeys(n.strip() for n in read_lines(names_path, "test list") if n.strip())) + unlisted, weights = read_weights(weights_path) + part_of, load = lay_out(set(names), unlisted, weights, parts) + mine = [name for name in names if part_of[name] == part] + for name in mine: + print(name) + print("part %d of %d runs %d of %d tests, about %.0f s by the weights (the parts: %s s)" % ( + part, parts, len(mine), len(names), load[part], ", ".join("%.0f" % l for l in load)), file=sys.stderr) + + +def check_unlisted(weights_path, log_path): + _, weights = read_weights(weights_path) + long = [] + for line in read_lines(log_path, "log"): + found = TOP.match(line) + if found and found.group(1) not in weights and float(found.group(2)) >= UNLISTED_CEILING: + long.append((found.group(1), float(found.group(2)))) + if long: + lines = "\n".join(" %.1f %s" % (took, name) for name, took in long) + refuse("these tests took %.0f s or more and the weights do not name them, so the parts are laid out " + "as if they were light:\n%s\nAdd each line above to %s." % (UNLISTED_CEILING, lines, weights_path)) + + +def main(): + args = sys.argv[1:] + if len(args) == 5 and args[0] == "split": + split(*args[1:]) + elif len(args) == 3 and args[0] == "unlisted": + check_unlisted(*args[1:]) + else: + refuse("usage: race_parts.py split NAMES WEIGHTS PART PARTS | race_parts.py unlisted WEIGHTS LOG") + + +if __name__ == "__main__": + main() diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 882d4147..337532ad 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -1049,7 +1049,9 @@ jobs: # a new definition was the weekly sweep, days after it merged. And so # is .github/build-tags, which every command of the job reads and which # decides the files it compiles - the same reason as go.mod, named by - # an outside review of the pull request that split the job. + # an outside review of the pull request that split the job. And so are + # the weights and the script that lay its parts out (O298), since a + # change to either decides which guards each part runs. # # Anything unclear counts as touched. A first push, a branch with no # comparable parent, a pull request event with no before - all answer @@ -1058,7 +1060,7 @@ jobs: # in somebody else's file. run: | set -euo pipefail - watched='internal/format/registry.go internal/damage/damage.go cmd/tfg/main.go internal/gui/window/run.go internal/gui/run_cgo.go internal/gui/window/tidy.go internal/audit/parallel.go internal/engine/parallel.go internal/tool/tool.go internal/gui/window/tools.go internal/format/video/ahead.go go.mod .github/workflows/ci.yml .github/build-tags' + watched='internal/format/registry.go internal/damage/damage.go cmd/tfg/main.go internal/gui/window/run.go internal/gui/run_cgo.go internal/gui/window/tidy.go internal/audit/parallel.go internal/engine/parallel.go internal/tool/tool.go internal/gui/window/tools.go internal/format/video/ahead.go go.mod .github/workflows/ci.yml .github/build-tags .github/race-weights .github/scripts/race_parts.py' # On a pull request there is no "before" - the field belongs to a push # - so this asked for something empty and every pull request answered # "touched". That quietly undid the decision of 2026-08-20, because @@ -1130,10 +1132,10 @@ jobs: # The ceiling is the sum of the limits inside it, with room left over, so # that each of them fires first and names what was slow: about four minutes # to set up and compile (the compile alone took 3m03s on the first run), - # twenty for the guards, five for the other packages. Measured on the first - # run, split by a sorted list: 677, 635, 164 and 154 s of guards in the - # four parts, 14m55s for the longest part. The two slowest guards take 329 - # and 222 s, and wherever they land together, that part is the slow one. + # twenty for the guards, five for the other packages. The guards are laid + # out by what each weighs (.github/race-weights), because a split by name + # gave parts of 1250, 1158, 795 and 526 s on the slowest processor + # measured, two of them at the twenty minutes (O298). strategy: fail-fast: false matrix: @@ -1172,14 +1174,13 @@ jobs: - name: the machine this part runs on # O298, 2026-11-03. Part 2 ran past its twenty minutes in one run of - # three since 2026-10-26, main included, while parts 0, 1 and 3 of the - # same runs took the time they always take. In a slow run every test of - # the part from the fourth on is about 1.75 times slower, the single - # threaded ones that read files among them. The log names the runner's - # image and region and nothing about the machine, so a slower machine - # and something inside the part could not be told apart. This says what - # the machine is, and the step after the tests says what its processor - # did meanwhile - the next slow run answers which of the two it was. + # three since 2026-10-26, main included, and the log named the runner's + # image and region and nothing about the machine. With this step the + # answer was the processor: the same part took 1202 s on an AMD EPYC + # 7763 and 689 s on an EPYC 9V45, every test of it slower by the same + # factor, while part 3 took 525 and 530 s on two 7763s. The weights + # the parts are laid out by come from these numbers, so this stays to + # say which processor a slow part had when the weights stop fitting. run: | set -euo pipefail echo "processors: $(nproc)" @@ -1203,13 +1204,16 @@ jobs: # because a file in the package builds only without it, and it keeps # Fuzz and Example because go test runs those as tests too. # - # A test's part is the checksum of its name (cksum) modulo the number - # of parts, so adding or removing a test moves no other test. It was - # every fourth name of a sorted list at first, and one guard added on - # this job's own pull request moved every name after it - the part - # holding the slowest guards changed from one commit to the next. The - # parts are even only on average, and which one is slow now changes only - # with what is in it. + # The tests .github/race-weights names are laid out by weight, the + # heaviest first, each into the part that is lightest so far. Every + # other test goes by the checksum of its name, so adding or removing a + # light test moves no other test. It was every fourth name of a sorted + # list at first, and one guard added on this job's own pull request + # moved every name after it. Then the checksum alone, which is even only + # on average, and with three guards of 330 to 350 s it was not. A test + # missing from the weights that takes a minute or more fails the part + # with the line to add, and a weight for a test that is gone fails + # every part, so the list cannot fall behind the tests quietly. # # Three things fail the part rather than let it pass on nothing - # go test with a -run pattern that matches no test exits 0. An index the @@ -1223,7 +1227,8 @@ jobs: # and stays below the job's ceiling, so a slow part fails as a test with # a name rather than as a killed job with no output. Go's ten minutes # killed this job on 2026-08-25, before a timeout was stated here. - # Twenty minutes is 1.8 times the slowest part measured. + # By the weights the heaviest part is 961 s on the slowest processor + # measured, and twenty minutes is 1.25 times that. # # The processor's counters and the clock are read just before the # tests, for the step after this one (O298). @@ -1240,12 +1245,7 @@ jobs: fi go test -tags "$(cat .github/build-tags)" ./internal/guard/ -race -list '.*' > listed.txt || { cat listed.txt; exit 1; } grep -E '^(Test|Fuzz|Example)' listed.txt > names.txt || { echo "the test binary listed no Test, Fuzz or Example function. What it printed:"; cat listed.txt; exit 1; } - while IFS= read -r name; do - read -r sum _ < <(printf '%s' "$name" | cksum) - if [ $((sum % PARTS)) -eq "$PART" ]; then - echo "$name" - fi - done < names.txt > mine.txt + python3 .github/scripts/race_parts.py split names.txt .github/race-weights "$PART" "$PARTS" > mine.txt planned=$(wc -l < mine.txt) echo "part $PART of $PARTS runs $planned of $(wc -l < names.txt) tests" if [ "$planned" -eq 0 ]; then @@ -1263,6 +1263,7 @@ jobs: echo "Each of these is a name the -run pattern did not reach, or a test the binary skipped before it started." exit 1 fi + python3 .github/scripts/race_parts.py unlisted .github/race-weights part.log shell: bash - name: what the processor did while this part ran diff --git a/internal/guard/mutation/entries.py b/internal/guard/mutation/entries.py index 35ac93a2..81593033 100644 --- a/internal/guard/mutation/entries.py +++ b/internal/guard/mutation/entries.py @@ -16477,4 +16477,97 @@ "manifestReachNote(saved.Size)...), []string(nil)...)", "TestTheWindowSaysWhenARunWillHoldMoreThanItsMemory", ), + ( + # O298: split by the checksum alone, the parts were 1250, 1158, 795 + # and 526 s on the slowest processor measured. + "the heavy guards of the race job are laid out by the checksum of their names like the light ones", + ".github/scripts/race_parts.py", + "part = min(range(parts), key=lambda p: (load[p], p))", + 'part = zlib.crc32(name.encode("utf-8")) % parts', + "TestTheRacePartsWeighAboutTheSame", + ), + ( + "a weight for a guard that was renamed is laid out without a word, and the renamed guard counts as light", + ".github/scripts/race_parts.py", + "gone = [name for name in weights if name not in names]", + "gone = []", + "TestTheRaceSplitRefusesWeightsItCannotTrust", + ), + ( + "every light guard is laid into every part of the race job", + ".github/scripts/race_parts.py", + "mine = [name for name in names if part_of[name] == part]", + "mine = [name for name in names if part_of[name] == part or name not in weights]", + "TestEveryGuardRunsInExactlyOneRacePart", + ), + ( + "a guard the weights do not name runs as long as it likes and its part stays green", + ".github/scripts/race_parts.py", + "float(found.group(2)) >= UNLISTED_CEILING", + "float(found.group(2)) >= UNLISTED_CEILING * 100", + "TestARaceTestMissingFromTheWeightsFailsItsPartWhenItRunsLong", + ), + ( + "a long subtest of a weighted guard fails its part as if it were a guard missing from the weights", + ".github/scripts/race_parts.py", + 'TOP = re.compile(r"^--- (?:PASS', + 'TOP = re.compile(r"^ *--- (?:PASS', + "TestARaceTestMissingFromTheWeightsFailsItsPartWhenItRunsLong", + ), + ( + "a weight below nought is taken and lightens its part", + ".github/scripts/race_parts.py", + "if not math.isfinite(value) or value < 0:", + "if not math.isfinite(value):", + "TestTheRaceSplitRefusesWeightsItCannotTrust", + ), + ( + "a guard weighed twice keeps the second weight without a word", + ".github/scripts/race_parts.py", + "if name in weights:", + "if name in ():", + "TestTheRaceSplitRefusesWeightsItCannotTrust", + ), + ( + "weights without an unlisted line count every light guard as nothing", + ".github/scripts/race_parts.py", + "unlisted = None", + "unlisted = 0.0", + "TestTheRaceSplitRefusesWeightsItCannotTrust", + ), + ( + "a part past the race job's parts is laid out as an empty part rather than refused", + ".github/scripts/race_parts.py", + "if parts < 1 or not 0 <= part < parts:", + "if parts < 1:", + "TestTheRaceSplitRefusesWeightsItCannotTrust", + ), + ( + "the race job stops laying its parts out by the weights", + ".github/workflows/ci.yml", + 'python3 .github/scripts/race_parts.py split names.txt .github/race-weights "$PART" "$PARTS" > mine.txt', + "cp names.txt mine.txt", + "TestTheRaceJobLaysItsPartsOutByTheWeights", + ), + ( + "the race job stops asking whether a guard missing from the weights ran long", + ".github/workflows/ci.yml", + " python3 .github/scripts/race_parts.py unlisted .github/race-weights part.log\n", + "", + "TestTheRaceJobLaysItsPartsOutByTheWeights", + ), + ( + "a weight names a guard the test binary no longer lists", + ".github/race-weights", + "348.3 TestAFormatRefusesASizeItCannotDescribe\n", + "348.3 TestAFormatRefusesASizeItCannotDescribeAnyMore\n", + "TestEveryGuardRunsInExactlyOneRacePart", + ), + ( + "a pull request that changes only the race weights or the script laying them out merges with the race job skipped", + ".github/workflows/ci.yml", + " .github/build-tags .github/race-weights .github/scripts/race_parts.py'", + " .github/build-tags'", + "TestTheRaceJobLaysItsPartsOutByTheWeights", + ), ] diff --git a/internal/guard/raceparts_test.go b/internal/guard/raceparts_test.go new file mode 100644 index 00000000..73ba9ee2 --- /dev/null +++ b/internal/guard/raceparts_test.go @@ -0,0 +1,306 @@ +package guard + +// The race job of ci.yml lays its guards out over its parts by what each +// weighs (O298, .github/race-weights, .github/scripts/race_parts.py). +// +// Measured before this existed: split by the checksum of each name, the four +// parts took about 1250, 1158, 795 and 526 s on the slowest processor a runner +// was given, and part 2 was killed at its twenty minutes in one run of three. +// The same part took 689 s on a faster processor, so the parts had to be even +// where the machine is slowest, not on average. + +import ( + "errors" + "os" + "os/exec" + "path/filepath" + "regexp" + "slices" + "strconv" + "strings" + "testing" +) + +// racePartsScript is the one place the script is named, so a move breaks one line. +func racePartsScript(t *testing.T) string { + t.Helper() + return filepath.Join(repoRoot(t), ".github", "scripts", "race_parts.py") +} + +// raceWeights is the weights file the race job lays its parts out by. +func raceWeights(t *testing.T) string { + t.Helper() + return filepath.Join(repoRoot(t), ".github", "race-weights") +} + +// runRaceParts runs the script and returns what it printed and its exit code. +func runRaceParts(t *testing.T, python string, args ...string) (stdout, stderr string, code int) { + t.Helper() + cmd := exec.Command(python, append([]string{racePartsScript(t)}, args...)...) + var out, errOut strings.Builder + cmd.Stdout, cmd.Stderr = &out, &errOut + err := cmd.Run() + var exit *exec.ExitError + switch { + case err == nil: + case errors.As(err, &exit): + code = exit.ExitCode() + default: + t.Fatalf("running %s: %v", racePartsScript(t), err) + } + return out.String(), errOut.String(), code +} + +// guardTestNames asks this test binary for its own tests, the way the race job +// asks with go test -list, so the layout is checked against the real list. +func guardTestNames(t *testing.T) []string { + t.Helper() + out, err := exec.Command(os.Args[0], "-test.list", ".*").Output() + if err != nil { + t.Fatalf("asking this test binary for its tests: %v", err) + } + var names []string + for _, line := range strings.Split(string(out), "\n") { + line = strings.TrimSpace(line) + if strings.HasPrefix(line, "Test") || strings.HasPrefix(line, "Fuzz") || strings.HasPrefix(line, "Example") { + names = append(names, line) + } + } + if len(names) < 100 { + t.Fatalf("this test binary listed %d tests, and the guard package has well over a thousand. What it printed:\n%s", len(names), out) + } + return names +} + +// raceJob reads what the race job states: its parts and its timeout in seconds. +func raceJob(t *testing.T) (parts int, timeout float64) { + t.Helper() + ci := readFile(t, filepath.Join(repoRoot(t), ".github", "workflows", "ci.yml")) + matrix := regexp.MustCompile(`(?m)^\s+part: \[([0-9, ]+)\]$`).FindAllStringSubmatch(ci, -1) + if len(matrix) != 1 { + t.Fatalf("ci.yml states the race job's parts %d times, and this reads exactly one strategy.matrix.part", len(matrix)) + } + parts = len(strings.Split(matrix[0][1], ",")) + limit := regexp.MustCompile(`\./internal/guard/ -count=1 -race -timeout ([0-9]+)m `).FindAllStringSubmatch(ci, -1) + if len(limit) != 1 { + t.Fatalf("ci.yml runs the guards under the race detector with a stated timeout %d times, and this reads exactly one", len(limit)) + } + minutes, _ := strconv.Atoi(limit[0][1]) + return parts, float64(minutes * 60) +} + +// writeLines writes lines to a new file and returns its path. +func writeLines(t *testing.T, name string, lines ...string) string { + t.Helper() + path := filepath.Join(t.TempDir(), name) + if err := os.WriteFile(path, []byte(strings.Join(lines, "\n")+"\n"), 0o600); err != nil { + t.Fatalf("writing %s: %v", name, err) + } + return path +} + +// splitInto returns the names each part of `parts` runs. +func splitInto(t *testing.T, python, names, weights string, parts int) [][]string { + t.Helper() + got := make([][]string, parts) + for part := range parts { + out, errOut, code := runRaceParts(t, python, "split", names, weights, strconv.Itoa(part), strconv.Itoa(parts)) + if code != 0 { + t.Fatalf("part %d of %d was refused (exit %d):\n%s", part, parts, code, errOut) + } + got[part] = strings.Fields(out) + } + return got +} + +// Every guard runs in exactly one part, whatever the number of parts. +// +// The job also compares the names it started with the names it was given, but +// only within a part. A test laid into no part, or into two, is invisible there. +func TestEveryGuardRunsInExactlyOneRacePart(t *testing.T) { + python := pythonForGate(t) + names := guardTestNames(t) + list := writeLines(t, "names.txt", names...) + matrix, _ := raceJob(t) + for _, parts := range []int{1, matrix, matrix + 1} { + seen := map[string]int{} + for part, mine := range splitInto(t, python, list, raceWeights(t), parts) { + for _, name := range mine { + if prior, twice := seen[name]; twice { + t.Fatalf("with %d parts, %s is laid into part %d and part %d, so it runs twice", parts, name, prior, part) + } + seen[name] = part + } + } + for _, name := range names { + if _, ok := seen[name]; !ok { + t.Errorf("with %d parts, %s is laid into no part, so the race detector never runs it", parts, name) + } + } + if len(seen) != len(names) { + t.Errorf("with %d parts the parts hold %d names and the binary lists %d", parts, len(seen), len(names)) + } + } +} + +// The parts weigh about the same by the weights, and the heaviest leaves room +// inside its timeout. +// +// The weights are the longest time each test took, so this is the layout where +// the machine is slowest. A part a tenth over the mean is uneven enough to +// matter, and a part past 85% of its timeout is one slower processor from red. +func TestTheRacePartsWeighAboutTheSame(t *testing.T) { + python := pythonForGate(t) + names := guardTestNames(t) + parts, timeout := raceJob(t) + unlisted, weights := readRaceWeights(t, raceWeights(t)) + load := make([]float64, parts) + total := 0.0 + for part, mine := range splitInto(t, python, writeLines(t, "names.txt", names...), raceWeights(t), parts) { + for _, name := range mine { + w, ok := weights[name] + if !ok { + w = unlisted + } + load[part] += w + total += w + } + } + mean := total / float64(parts) + for part, l := range load { + if l > 1.1*mean { + t.Errorf("part %d of %d weighs %.0f s against a mean of %.0f s (all parts: %.0f).\n"+ + "The heavy guards are no longer laid out by weight, and the heaviest part is the one the timeout ends.", + part, parts, l, mean, load) + } + if l > 0.85*timeout { + t.Errorf("part %d of %d weighs %.0f s, past 85%% of its %.0f s timeout.\n"+ + "Add a part to strategy.matrix.part in ci.yml rather than raising the timeout.", part, parts, l, timeout) + } + } +} + +// readRaceWeights reads the weights file the way the script does, for the +// cases where this guard has to weigh a part itself. +func readRaceWeights(t *testing.T, path string) (unlisted float64, weights map[string]float64) { + t.Helper() + weights = map[string]float64{} + unlisted = -1 + for _, line := range strings.Split(readFile(t, path), "\n") { + fields := strings.Fields(line) + if len(fields) == 0 || strings.HasPrefix(fields[0], "#") { + continue + } + if len(fields) != 2 { + t.Fatalf("%s holds a line that is not a weight: %q", path, line) + } + if fields[0] == "unlisted" { + unlisted, _ = strconv.ParseFloat(fields[1], 64) + continue + } + w, err := strconv.ParseFloat(fields[0], 64) + if err != nil { + t.Fatalf("%s holds a weight that is not a number: %q", path, line) + } + weights[fields[1]] = w + } + if unlisted < 0 || len(weights) == 0 { + t.Fatalf("%s has no unlisted weight or no test named, so there is nothing to lay out by", path) + } + return unlisted, weights +} + +// The script refuses weights it cannot trust, and says what to change. +// +// A weight for a test that was renamed is the way this list falls behind: the +// renamed test would be laid out as light and nothing would say so. +func TestTheRaceSplitRefusesWeightsItCannotTrust(t *testing.T) { + python := pythonForGate(t) + names := writeLines(t, "names.txt", "TestOne", "TestTwo", "TestThree") + cases := []struct { + name string + weights []string + part string + says string + }{ + {"a test that is gone", []string{"unlisted 1", "30 TestGone"}, "0", "TestGone, which the test binary does not list"}, + {"a line that is not a weight", []string{"unlisted 1", "thirty TestOne"}, "0", "a weight is a number of seconds"}, + {"a weight below nought", []string{"unlisted 1", "-3 TestOne"}, "0", "a weight is a number of seconds"}, + {"a test named twice", []string{"unlisted 1", "30 TestOne", "20 TestOne"}, "0", "names TestOne a second time"}, + {"no unlisted weight", []string{"30 TestOne"}, "0", "has no \"unlisted\" line"}, + {"a part past the parts", []string{"unlisted 1", "30 TestOne"}, "4", "part 4 of 4 does not exist"}, + } + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + out, errOut, code := runRaceParts(t, python, "split", names, writeLines(t, "weights", c.weights...), c.part, "4") + if code == 0 { + t.Fatalf("the split accepted weights with %s and laid out:\n%s", c.name, out) + } + if !strings.Contains(errOut, c.says) { + t.Errorf("the split refused weights with %s without saying %q. It said:\n%s", c.name, c.says, errOut) + } + }) + } + if _, errOut, code := runRaceParts(t, python, "split", names, writeLines(t, "weights", "unlisted 1", "30 TestOne"), "0", "4"); code != 0 { + t.Fatalf("the split refused weights that are right, so the cases above prove nothing:\n%s", errOut) + } +} + +// A test the weights do not name fails its part once it runs a minute. +// +// Such a test is laid out as light, so the parts stop being even, and the +// timeout would say so only when the part is already lost. +func TestARaceTestMissingFromTheWeightsFailsItsPartWhenItRunsLong(t *testing.T) { + python := pythonForGate(t) + weights := writeLines(t, "weights", "unlisted 0.5", "300 TestHeavy") + quiet := []string{ + "--- PASS: TestHeavy (500.00s)", + "--- PASS: TestLight (59.90s)", + " --- PASS: TestLight/long_subtest (90.00s)", + "--- SKIP: TestSkipped (0.00s)", + } + if _, errOut, code := runRaceParts(t, python, "unlisted", weights, writeLines(t, "part.log", quiet...)); code != 0 { + t.Fatalf("a part whose only long tests are weighted, or are subtests, failed:\n%s", errOut) + } + long := append(quiet, "--- FAIL: TestNew (60.00s)") + _, errOut, code := runRaceParts(t, python, "unlisted", weights, writeLines(t, "part.log", long...)) + if code == 0 { + t.Fatal("a test the weights do not name ran 60 s and its part passed, so the weights can fall behind the tests without a word") + } + if !strings.Contains(errOut, "60.0 TestNew") { + t.Errorf("the part failed without giving the line to add for TestNew. It said:\n%s", errOut) + } +} + +// The race job lays its parts out with the script, asks about unlisted tests +// after its tests ran, and runs when either file changes. +// +// The job runs only on a push that touches one of its watched files, so a pull +// request changing nothing but the weights would merge them unrun. +func TestTheRaceJobLaysItsPartsOutByTheWeights(t *testing.T) { + ci := readFile(t, filepath.Join(repoRoot(t), ".github", "workflows", "ci.yml")) + watched := regexp.MustCompile(`(?m)^\s+watched='([^']*)'$`).FindAllStringSubmatch(ci, -1) + if len(watched) != 1 { + t.Fatalf("ci.yml sets the race job's watched files %d times, and this reads exactly one", len(watched)) + } + files := strings.Fields(watched[0][1]) + for _, want := range []string{".github/race-weights", ".github/scripts/race_parts.py"} { + if !slices.Contains(files, want) { + t.Errorf("the race job does not run when %s changes, so a change to how its parts are laid out merges unrun", want) + } + } + split := `python3 .github/scripts/race_parts.py split names.txt .github/race-weights "$PART" "$PARTS" > mine.txt` + unlisted := `python3 .github/scripts/race_parts.py unlisted .github/race-weights part.log` + for _, line := range []string{split, unlisted} { + if n := strings.Count(ci, line); n != 1 { + t.Errorf("ci.yml holds %d copies of\n %s\nand the race job needs exactly one", n, line) + } + } + if strings.Contains(ci, "| cksum)") { + t.Error("ci.yml still lays the race parts out by the checksum of each name alone") + } + tee, after := strings.Index(ci, "| tee part.log"), strings.Index(ci, unlisted) + if tee < 0 || after < tee { + t.Error("ci.yml asks about unlisted tests before the part's log is written, so it reads nothing") + } +} From dc4d16a60728cf0f449dbb03ac5038362526b510 Mon Sep 17 00:00:00 2001 From: DonislawDev Date: Tue, 3 Nov 2026 19:02:11 +0100 Subject: [PATCH 2/2] ci: the race split reads only the durations go test writes, and its guards handle every parse error A log line whose duration is not one go test writes is passed by rather than ending the unlisted check with a traceback, and a file that cannot be read says so in a sentence. The guards fail on a timeout or an unlisted weight that is not a number instead of reading it as nought. The mutation entry for the missing unlisted line now changes only that refusal, and a new one covers the duration pattern. Co-Authored-By: Claude Opus 5.5 --- .github/scripts/race_parts.py | 10 +++++++--- internal/guard/mutation/entries.py | 16 +++++++++++++--- internal/guard/raceparts_test.go | 13 ++++++++++--- 3 files changed, 30 insertions(+), 9 deletions(-) diff --git a/.github/scripts/race_parts.py b/.github/scripts/race_parts.py index d6757c2a..0d82b803 100644 --- a/.github/scripts/race_parts.py +++ b/.github/scripts/race_parts.py @@ -31,7 +31,9 @@ # made slow. UNLISTED_CEILING = 60.0 -TOP = re.compile(r"^--- (?:PASS|FAIL|SKIP): (\S+) \(([0-9.]+)s\)$") +# A duration as go test writes it. A looser one let "1.2.3s" through to float(), +# which ended the script with a traceback instead of passing the line by. +TOP = re.compile(r"^--- (?:PASS|FAIL|SKIP): (\S+) \(([0-9]+(?:\.[0-9]+)?)s\)$") def refuse(message): @@ -43,8 +45,10 @@ def read_lines(path, what): try: with open(path, encoding="utf-8") as f: return f.read().splitlines() - except (OSError, UnicodeDecodeError) as err: - refuse("cannot read the %s %s: %s" % (what, path, err)) + except UnicodeDecodeError: + refuse("the %s %s is not UTF-8 text, so it is not one this job wrote." % (what, path)) + except OSError as err: + refuse("cannot read the %s %s: %s." % (what, path, err.strerror or err)) def read_weights(path): diff --git a/internal/guard/mutation/entries.py b/internal/guard/mutation/entries.py index 81593033..02b76cef 100644 --- a/internal/guard/mutation/entries.py +++ b/internal/guard/mutation/entries.py @@ -16529,12 +16529,22 @@ "TestTheRaceSplitRefusesWeightsItCannotTrust", ), ( - "weights without an unlisted line count every light guard as nothing", + # Only the refusal of a missing line. Starting the weight at 0.0 + # instead made the first "unlisted" line look like a second one, so + # the entry was caught for another reason (#216 review). + "weights without an unlisted line are taken rather than refused with the line to add", ".github/scripts/race_parts.py", - "unlisted = None", - "unlisted = 0.0", + "if unlisted is None:", + "if unlisted is None and False:", "TestTheRaceSplitRefusesWeightsItCannotTrust", ), + ( + "a race log line whose duration is not one go test writes ends the unlisted check with a traceback", + ".github/scripts/race_parts.py", + "([0-9]+(?:", + "([0-9.]+(?:", + "TestARaceTestMissingFromTheWeightsFailsItsPartWhenItRunsLong", + ), ( "a part past the race job's parts is laid out as an empty part rather than refused", ".github/scripts/race_parts.py", diff --git a/internal/guard/raceparts_test.go b/internal/guard/raceparts_test.go index 73ba9ee2..89e65b20 100644 --- a/internal/guard/raceparts_test.go +++ b/internal/guard/raceparts_test.go @@ -85,7 +85,10 @@ func raceJob(t *testing.T) (parts int, timeout float64) { if len(limit) != 1 { t.Fatalf("ci.yml runs the guards under the race detector with a stated timeout %d times, and this reads exactly one", len(limit)) } - minutes, _ := strconv.Atoi(limit[0][1]) + minutes, err := strconv.Atoi(limit[0][1]) + if err != nil { + t.Fatalf("ci.yml states the guard timeout as %q, which is not a number of minutes: %v", limit[0][1], err) + } return parts, float64(minutes * 60) } @@ -195,7 +198,10 @@ func readRaceWeights(t *testing.T, path string) (unlisted float64, weights map[s t.Fatalf("%s holds a line that is not a weight: %q", path, line) } if fields[0] == "unlisted" { - unlisted, _ = strconv.ParseFloat(fields[1], 64) + var err error + if unlisted, err = strconv.ParseFloat(fields[1], 64); err != nil { + t.Fatalf("%s holds an unlisted weight that is not a number: %q", path, line) + } continue } w, err := strconv.ParseFloat(fields[0], 64) @@ -258,9 +264,10 @@ func TestARaceTestMissingFromTheWeightsFailsItsPartWhenItRunsLong(t *testing.T) "--- PASS: TestLight (59.90s)", " --- PASS: TestLight/long_subtest (90.00s)", "--- SKIP: TestSkipped (0.00s)", + "--- PASS: TestOdd (1.2.3s)", } if _, errOut, code := runRaceParts(t, python, "unlisted", weights, writeLines(t, "part.log", quiet...)); code != 0 { - t.Fatalf("a part whose only long tests are weighted, or are subtests, failed:\n%s", errOut) + t.Fatalf("a part whose only long tests are weighted, or are subtests, or whose one odd line is not a duration go test writes, failed:\n%s", errOut) } long := append(quiet, "--- FAIL: TestNew (60.00s)") _, errOut, code := runRaceParts(t, python, "unlisted", weights, writeLines(t, "part.log", long...))