Skip to content

Commit e8a767b

Browse files
mknyszekgopherbot
authored andcommitted
runtime/pprof: increase contention upper bound in TestMutexProfile
Currently TestMutexProfile expects contention to reported as somewhere between 0.9x and 2.0x the expected amount introduced. While bounding from below is fine (especially since the goroutine holding the mutex doesn't even start to sleep until the required number of goroutines are blocked on a mutex), bounding from above can easily lead to flakiness. Delays and non-determinism can come from anywhere in the system, and nevertheless clocks keep ticking. The result is that goroutines could easily appear to be blocked on a mutex much longer than just the sleep time. However, the contention upper bound is still useful, especially for identifying wildly incorrect values. Set the contention total to be proportional to the total wall-time spent in the actual sampling mutex block sampling portion of the code. This should be a generous upper-bound on how much contention there could be, because it should in theory capture any delays from the environment in it as well. Still, rounding errors could be an issue, and on Windows the time granularity is quite low (~15ms, or 15% of what each goroutine is supposed to add to the mutex profile), so getting unlucky with where time measurements fall within each tick could also be a problem. Add an extra 10%, which seems to make it much less likely to fail in a Windows gomote. Fixes #62094. Change-Id: I59a10a73affd077185dada8474b91d0bc43b4a43 Reviewed-on: https://go-review.googlesource.com/c/go/+/520635 Auto-Submit: Michael Knyszek <[email protected]> Reviewed-by: Bryan Mills <[email protected]> TryBot-Result: Gopher Robot <[email protected]> Run-TryBot: Michael Knyszek <[email protected]>
1 parent b65e34f commit e8a767b

File tree

1 file changed

+17
-2
lines changed

1 file changed

+17
-2
lines changed

src/runtime/pprof/pprof_test.go

+17-2
Original file line numberDiff line numberDiff line change
@@ -1245,7 +1245,9 @@ func TestMutexProfile(t *testing.T) {
12451245
N = 100
12461246
D = 100 * time.Millisecond
12471247
)
1248+
start := time.Now()
12481249
blockMutexN(t, N, D)
1250+
blockMutexNTime := time.Since(start)
12491251

12501252
t.Run("debug=1", func(t *testing.T) {
12511253
var w strings.Builder
@@ -1307,9 +1309,22 @@ func TestMutexProfile(t *testing.T) {
13071309
for _, s := range p.Sample {
13081310
total += s.Value[i]
13091311
}
1312+
// Want d to be at least N*D, but give some wiggle-room to avoid
1313+
// a test flaking. Set an upper-bound proportional to the total
1314+
// wall time spent in blockMutexN. Generally speaking, the total
1315+
// contention time could be arbitrarily high when considering
1316+
// OS scheduler delays, or any other delays from the environment:
1317+
// time keeps ticking during these delays. By making the upper
1318+
// bound proportional to the wall time in blockMutexN, in theory
1319+
// we're accounting for all these possible delays.
13101320
d := time.Duration(total)
1311-
if d < N*D*9/10 || d > N*D*2 { // want N*D but allow [0.9,2.0]*that.
1312-
t.Fatalf("profile samples total %v, want %v", d, N*D)
1321+
lo := time.Duration(N * D * 9 / 10)
1322+
hi := time.Duration(N) * blockMutexNTime * 11 / 10
1323+
if d < lo || d > hi {
1324+
for _, s := range p.Sample {
1325+
t.Logf("sample: %s", time.Duration(s.Value[i]))
1326+
}
1327+
t.Fatalf("profile samples total %v, want within range [%v, %v] (target: %v)", d, lo, hi, N*D)
13131328
}
13141329
})
13151330
}

0 commit comments

Comments
 (0)