From 8aa1f3616088ba270ba1aeba60221b654dd73410 Mon Sep 17 00:00:00 2001 From: tannevaled Date: Sun, 4 Oct 2026 15:41:46 +0200 Subject: [PATCH] Three timing tests take their two minima INTERLEAVED, not in blocks TestAThreeComponentJPEGIsCachedOnItsSampleTriple failed once during other work, reporting 8.9x against a threshold of 3x, and passed three times in a row alone a minute later. The load average was 59. Each of the three tests took three draws of the witness, then three of the subject, and compared the minima. That is enough to fail on a busy machine: the witness can take all three of its turns in a quiet moment and the subject all three of its own under a spike, and the ratio then reports the machine rather than the code. MEASURED rather than argued, because the failure could not be reproduced on demand. A throwaway test computed the ratio BOTH WAYS on the same work, 40 rounds per scheme per run, under load: max of 40 max of 40 max of 40 over 3x blocked 1.61 2.27 8.80 1 of 120 interleaved 1.53 1.52 1.61 0 of 120 The 8.80 is the failure, reproduced -- and close to the 8.9 that started this. The blocked scheme also returned a ratio of 0.50 in the first run, which says the calibrated subject ran twice as fast as the device witness: impossible for the quantity being measured, and a direct demonstration that its two minima come from two different moments. So pairedBest draws the two alternately and keeps each one's minimum. Its comment carries the numbers above, because a test whose threshold is a ratio needs a reader to know what the ratio's own spread is. The fourth ratio assertion in the suite is left alone: TestAType3GlyphThatShowsItselfIsRefusedRatherThanBounded compares OPERATION COUNTS, and says in its own comment why that is not a duration. It cannot drift with load and does not need this. 100.0% of statements. --- build_test.go | 48 +++++++++++++++++++++++++++++++++++++++++++ jpegspace_test.go | 52 ++++++++--------------------------------------- 2 files changed, 57 insertions(+), 43 deletions(-) diff --git a/build_test.go b/build_test.go index a835a5c..83c068f 100644 --- a/build_test.go +++ b/build_test.go @@ -4,6 +4,7 @@ import ( "fmt" "image/color" "testing" + "time" "github.com/go-gfx/gfx/raster" "github.com/go-pdfkit/reader" @@ -115,3 +116,50 @@ func inked(img *raster.Image) int { } return n } + +// pairedBest draws two documents ALTERNATELY and returns the shortest each +// took, which is what a test comparing the two should ask for. +// +// Three runs of one followed by three of the other is enough to fail on a busy +// machine: the witness can take all three of its turns in a quiet moment and +// the subject all three of its own under a spike, and the ratio then reports +// the machine rather than the code. Alternating puts every spike inside one +// ROUND, where it falls on both sides. +// +// Seen once, 2026-10-04: TestAThreeComponentJPEGIsCachedOnItsSampleTriple +// reported 8.9x at a load average of 59, and the same build passed three times +// in a row a minute later. The ratio was real and it was a ratio of two +// different moments. +// +// MEASURED, because that failure could not be reproduced on demand. A +// throwaway test computed the ratio both ways on the same work, forty rounds +// per scheme per run, under load: +// +// max of 40 max of 40 max of 40 over 3x +// blocked 1.61 2.27 8.80 1 of 120 +// interleaved 1.53 1.52 1.61 0 of 120 +// +// The 8.80 is the failure reproduced. The blocked scheme also returned 0.50 +// once, which says the calibrated subject ran twice as fast as the device +// witness -- impossible for the quantity being measured, and the plainest +// demonstration that its two minima come from two different moments. +// +// A warm-up draw of each is the caller's business, and all three callers do it: +// the first draw of a page pays for whatever is cached once. +func pairedBest(t *testing.T, witness, subject *reader.Document, rounds int) (time.Duration, time.Duration) { + t.Helper() + w, s := time.Duration(1<<62), time.Duration(1<<62) + for i := 0; i < rounds; i++ { + start := time.Now() + draw(t, witness, Options{}) + if took := time.Since(start); took < w { + w = took + } + start = time.Now() + draw(t, subject, Options{}) + if took := time.Since(start); took < s { + s = took + } + } + return w, s +} diff --git a/jpegspace_test.go b/jpegspace_test.go index ed05bc3..c7e9b23 100644 --- a/jpegspace_test.go +++ b/jpegspace_test.go @@ -11,7 +11,6 @@ import ( "image" "image/jpeg" "testing" - "time" "github.com/go-pdfkit/reader" ) @@ -279,20 +278,9 @@ func TestAOneComponentJPEGIsConvertedOncePerLevelRatherThanOncePerPixel(t *testi draw(t, gradientJPEGPage(t, side, device), Options{}) draw(t, gradientJPEGPage(t, side, calibrated), Options{}) - best := func(space func(*reader.Writer) reader.Object) time.Duration { - d := gradientJPEGPage(t, side, space) - out := time.Duration(1 << 62) - for i := 0; i < 3; i++ { - start := time.Now() - draw(t, d, Options{}) - if took := time.Since(start); took < out { - out = took - } - } - return out - } - witness := best(device) - subject := best(calibrated) + witness, subject := pairedBest(t, + gradientJPEGPage(t, side, device), + gradientJPEGPage(t, side, calibrated), 3) if subject > 3*witness { t.Errorf("a calibrated grey JPEG took %v against DeviceGray's %v (%.1fx); "+ "the colour space is being asked per pixel rather than per level", @@ -451,20 +439,9 @@ func TestAThreeComponentJPEGIsCachedOnItsSampleTriple(t *testing.T) { draw(t, rgbJPEGPage(t, side, deviceRGB, fill), Options{}) draw(t, rgbJPEGPage(t, side, calRGB, fill), Options{}) - best := func(space func(*reader.Writer) reader.Object) time.Duration { - d := rgbJPEGPage(t, side, space, fill) - out := time.Duration(1 << 62) - for i := 0; i < 3; i++ { - start := time.Now() - draw(t, d, Options{}) - if took := time.Since(start); took < out { - out = took - } - } - return out - } - witness := best(deviceRGB) - subject := best(calRGB) + witness, subject := pairedBest(t, + rgbJPEGPage(t, side, deviceRGB, fill), + rgbJPEGPage(t, side, calRGB, fill), 3) if subject > 3*witness { t.Errorf("a calibrated RGB JPEG took %v against DeviceRGB's %v (%.1fx); "+ "the colour space is being asked per pixel rather than per distinct triple", @@ -634,20 +611,9 @@ func TestManySmallPicturesDoNotEachPayForTheTable(t *testing.T) { draw(t, manyTinyJPEGsPage(t, n, deviceRGB), Options{}) draw(t, manyTinyJPEGsPage(t, n, calRGB), Options{}) - best := func(space func(*reader.Writer) reader.Object) time.Duration { - d := manyTinyJPEGsPage(t, n, space) - out := time.Duration(1 << 62) - for i := 0; i < 3; i++ { - start := time.Now() - draw(t, d, Options{}) - if took := time.Since(start); took < out { - out = took - } - } - return out - } - witness := best(deviceRGB) - subject := best(calRGB) + witness, subject := pairedBest(t, + manyTinyJPEGsPage(t, n, deviceRGB), + manyTinyJPEGsPage(t, n, calRGB), 3) if subject > 3*witness { t.Errorf("%d small calibrated pictures took %v against DeviceRGB's %v (%.1fx); "+ "each picture is paying for its own cache", n, subject, witness,