Skip to content

Commit 1c510bf

Browse files
authored
test: deflake TestBaseMetricObject with testing/synctest (#2686)
# Description `TestBaseMetricObject` races against real timers and fails intermittently in the `Test Retina Image` workflow. It failed two runs in the last week: [Aug 23, merge queue](https://github.com/microsoft/retina/actions/runs/32652429087), [Aug 24, PR run](https://github.com/microsoft/retina/actions/runs/32736068992/attempts/2). The second failure sits in an earlier attempt of a re-run, so the run list hides it. ``` basemetricsobject_test.go:100: expected number of goroutines to be the same as before, expected 4, got 3 ``` The test has three timing defects: - It compares two process-wide `runtime.NumGoroutine()` snapshots. Unrelated goroutine churn breaks the comparison. This caused both CI failures. - It sleeps `101ms`, then reads `expireCalled`. The expiration goroutine writes that variable. The race detector reports the pair. - The expiration ticker starts before `b.updated`. A late first assertion can observe the label already expired. This PR moves the test body into a `testing/synctest` bubble (standard library since Go 1.25 — `go.mod` requires `go 1.26.0`): - The fake clock makes the ticker fire deterministically and removes all real sleeps. This closes the early-expiration gap. - `synctest.Wait()` orders the callback write before the test reads it. This removes the data race. - The bubble fails the test if the expiration goroutine leaks. This replaces the process-wide count. `t.Cleanup(b.clean)` stops the goroutine on every exit path. ## Checklist - [x] I have read the [contributing documentation](https://retina.sh/docs/Contributing/overview). - [x] I signed and signed-off the commits (`git commit -S -s ...`). See [this documentation](https://docs.github.com/en/authentication/managing-commit-signature-verification/about-commit-signature-verification) on signing commits. - [x] I have correctly attributed the author(s) of the code. - [x] I have tested the changes locally. - [x] I have followed the project's style guidelines. - [ ] I have updated the documentation, if necessary. - [ ] I have added tests, if applicable. ## Screenshots (if applicable) or Testing Completed ```bash go test -tags=unit,dashboard -run 'TestBaseMetricObject' -count=100 ./pkg/module/metrics/ go test -race -tags=unit,dashboard -run 'TestBaseMetricObject' -count=100 ./pkg/module/metrics/ ``` Both pass. The 100 plain iterations complete in `0.04s` because the bubble removes the real sleeps. Before this change, the race detector failed the test on the first run. `go vet` is clean on the package. Signed-off-by: Quang Nguyen <28567936+nddq@users.noreply.github.com>
1 parent 366a5e0 commit 1c510bf

1 file changed

Lines changed: 46 additions & 53 deletions

File tree

pkg/module/metrics/basemetricsobject_test.go

Lines changed: 46 additions & 53 deletions
Original file line numberDiff line numberDiff line change
@@ -3,9 +3,9 @@
33
package metrics
44

55
import (
6-
"runtime"
76
"slices"
87
"testing"
8+
"testing/synctest"
99
"time"
1010

1111
api "github.com/microsoft/retina/crd/api/v1alpha1"
@@ -42,63 +42,56 @@ func TestBaseMetricObject(t *testing.T) {
4242

4343
for _, tt := range tests {
4444
t.Run(tt.name, func(t *testing.T) {
45-
before := runtime.NumGoroutine()
46-
expireCalled := new([]string)
47-
b := newBaseMetricsObject(
48-
&api.MetricsContextOptions{
49-
MetricName: "test_metric",
50-
},
51-
l,
52-
localContext,
53-
func(lbs []string) bool {
54-
*expireCalled = lbs
55-
return true
56-
},
57-
tt.ttl,
58-
)
45+
// The bubble gives the test a fake clock, so the expiration
46+
// ticker fires deterministically. It also fails the test if the
47+
// expiration goroutine is still alive when the bubble ends.
48+
synctest.Test(t, func(t *testing.T) {
49+
var expireCalled []string
50+
b := newBaseMetricsObject(
51+
&api.MetricsContextOptions{
52+
MetricName: "test_metric",
53+
},
54+
l,
55+
localContext,
56+
func(lbs []string) bool {
57+
expireCalled = lbs
58+
return true
59+
},
60+
tt.ttl,
61+
)
62+
t.Cleanup(b.clean)
5963

60-
testLabels := []string{"test"}
61-
b.updated(testLabels)
64+
testLabels := []string{"test"}
65+
b.updated(testLabels)
6266

63-
metrics := len(b.trackedMetricLabels())
64-
if tt.trackMetrics {
65-
if metrics != 1 {
66-
t.Errorf("expected 1 tracked metric label, got %d", metrics)
67+
metrics := len(b.trackedMetricLabels())
68+
if tt.trackMetrics {
69+
if metrics != 1 {
70+
t.Errorf("expected 1 tracked metric label, got %d", metrics)
71+
}
72+
} else {
73+
if metrics != 0 {
74+
t.Errorf("expected 0 tracked metric labels, got %d", metrics)
75+
}
6776
}
68-
} else {
69-
if metrics != 0 {
70-
t.Errorf("expected 0 tracked metric labels, got %d", metrics)
71-
}
72-
}
7377

74-
// If we have a positive TTL, we should see the expire function get called after the TTL has passed
75-
if tt.ttl > 0 {
76-
time.Sleep(tt.ttl + time.Millisecond*100)
77-
if !slices.Equal(*expireCalled, testLabels) {
78-
t.Errorf("expected expire to be called with %v, got %v", testLabels, *expireCalled)
79-
}
80-
metrics = len(b.trackedMetricLabels())
81-
if metrics != 0 {
82-
t.Errorf("expected 0 tracked metric labels after expiration, got %d", metrics)
78+
// If we have a positive TTL, we should see the expire function get called after the TTL has passed
79+
if tt.ttl > 0 {
80+
// Advance the fake clock to the first tick, then wait for
81+
// the expiration goroutine to block again.
82+
time.Sleep(tt.ttl)
83+
synctest.Wait()
84+
if !slices.Equal(expireCalled, testLabels) {
85+
t.Errorf("expected expire to be called with %v, got %v", testLabels, expireCalled)
86+
}
87+
metrics = len(b.trackedMetricLabels())
88+
if metrics != 0 {
89+
t.Errorf("expected 0 tracked metric labels after expiration, got %d", metrics)
90+
}
91+
} else if len(expireCalled) != 0 {
92+
t.Errorf("expected expire to not be called, but got %v", expireCalled)
8393
}
84-
} else if len(*expireCalled) != 0 {
85-
t.Errorf("expected expire to not be called, but got %v", *expireCalled)
86-
}
87-
88-
b.clean()
89-
if b.expireFn != nil {
90-
<-b.ctx.Done()
91-
}
92-
93-
// Wait for any goroutines to exit after clean is called
94-
if tt.trackMetrics {
95-
time.Sleep(tt.ttl + time.Millisecond*100)
96-
}
97-
98-
after := runtime.NumGoroutine()
99-
if after != before {
100-
t.Errorf("expected number of goroutines to be the same as before, expected %d, got %d", before, after)
101-
}
94+
})
10295
})
10396
}
10497
}

0 commit comments

Comments
 (0)