Skip to content

Commit d59bd25

Browse files
rhyshgopherbot
authored andcommitted
runtime: test for contention in both semaphore paths
Most contention on the runtime locks inside semaphores is observed in runtime.semrelease1, but it can also appear in runtime.semacquire1. When examining contention profiles in TestRuntimeLockMetricsAndProfile, allow call stacks that include either. For #64253 Change-Id: Id4f16af5e9a28615ab5032a3197e8df90f7e382f Reviewed-on: https://go-review.googlesource.com/c/go/+/544375 Reviewed-by: Dmitri Shuralyov <[email protected]> Auto-Submit: Rhys Hiltner <[email protected]> LUCI-TryBot-Result: Go LUCI <[email protected]> Reviewed-by: Michael Knyszek <[email protected]>
1 parent 46410b7 commit d59bd25

File tree

1 file changed

+51
-25
lines changed

1 file changed

+51
-25
lines changed

src/runtime/metrics_test.go

+51-25
Original file line numberDiff line numberDiff line change
@@ -1018,7 +1018,7 @@ func TestRuntimeLockMetricsAndProfile(t *testing.T) {
10181018
return metricGrowth, profileGrowth, p
10191019
}
10201020

1021-
testcase := func(strictTiming bool, stk []string, workers int, fn func() bool) func(t *testing.T) (metricGrowth, profileGrowth float64, n, value int64) {
1021+
testcase := func(strictTiming bool, acceptStacks [][]string, workers int, fn func() bool) func(t *testing.T) (metricGrowth, profileGrowth float64, n, value int64) {
10221022
return func(t *testing.T) (metricGrowth, profileGrowth float64, n, value int64) {
10231023
metricGrowth, profileGrowth, p := measureDelta(t, func() {
10241024
var started, stopped sync.WaitGroup
@@ -1056,19 +1056,24 @@ func TestRuntimeLockMetricsAndProfile(t *testing.T) {
10561056
t.Logf("lock contention growth in runtime/pprof's view (%fs)", profileGrowth)
10571057
t.Logf("lock contention growth in runtime/metrics' view (%fs)", metricGrowth)
10581058

1059-
if goexperiment.StaticLockRanking {
1060-
if !slices.ContainsFunc(stk, func(s string) bool {
1061-
return s == "runtime.systemstack" || s == "runtime.mcall" || s == "runtime.mstart"
1062-
}) {
1063-
// stk is a call stack that is still on the user stack when
1064-
// it calls runtime.unlock. Add the extra function that
1065-
// we'll see, when the static lock ranking implementation of
1066-
// runtime.unlockWithRank switches to the system stack.
1067-
stk = append([]string{"runtime.unlockWithRank"}, stk...)
1059+
acceptStacks = append([][]string(nil), acceptStacks...)
1060+
for i, stk := range acceptStacks {
1061+
if goexperiment.StaticLockRanking {
1062+
if !slices.ContainsFunc(stk, func(s string) bool {
1063+
return s == "runtime.systemstack" || s == "runtime.mcall" || s == "runtime.mstart"
1064+
}) {
1065+
// stk is a call stack that is still on the user stack when
1066+
// it calls runtime.unlock. Add the extra function that
1067+
// we'll see, when the static lock ranking implementation of
1068+
// runtime.unlockWithRank switches to the system stack.
1069+
stk = append([]string{"runtime.unlockWithRank"}, stk...)
1070+
}
10681071
}
1072+
acceptStacks[i] = stk
10691073
}
10701074

10711075
var stks [][]string
1076+
values := make([][2]int64, len(acceptStacks))
10721077
for _, s := range p.Sample {
10731078
var have []string
10741079
for _, loc := range s.Location {
@@ -1077,18 +1082,26 @@ func TestRuntimeLockMetricsAndProfile(t *testing.T) {
10771082
}
10781083
}
10791084
stks = append(stks, have)
1080-
if slices.Equal(have, stk) {
1081-
n += s.Value[0]
1082-
value += s.Value[1]
1085+
for i, stk := range acceptStacks {
1086+
if slices.Equal(have, stk) {
1087+
values[i][0] += s.Value[0]
1088+
values[i][1] += s.Value[1]
1089+
}
10831090
}
10841091
}
1085-
t.Logf("stack %v has samples totaling n=%d value=%d", stk, n, value)
1092+
for i, stk := range acceptStacks {
1093+
n += values[i][0]
1094+
value += values[i][1]
1095+
t.Logf("stack %v has samples totaling n=%d value=%d", stk, values[i][0], values[i][1])
1096+
}
10861097
if n == 0 && value == 0 {
10871098
t.Logf("profile:\n%s", p)
10881099
for _, have := range stks {
10891100
t.Logf("have stack %v", have)
10901101
}
1091-
t.Errorf("want stack %v", stk)
1102+
for _, stk := range acceptStacks {
1103+
t.Errorf("want stack %v", stk)
1104+
}
10921105
}
10931106

10941107
return metricGrowth, profileGrowth, n, value
@@ -1140,18 +1153,18 @@ func TestRuntimeLockMetricsAndProfile(t *testing.T) {
11401153
return true
11411154
}
11421155

1143-
stk := []string{
1156+
stks := [][]string{{
11441157
"runtime.unlock",
11451158
"runtime_test." + name + ".func5.1",
11461159
"runtime_test.(*contentionWorker).run",
1147-
}
1160+
}}
11481161

11491162
t.Run("sample-1", func(t *testing.T) {
11501163
old := runtime.SetMutexProfileFraction(1)
11511164
defer runtime.SetMutexProfileFraction(old)
11521165

11531166
needContention.Store(int64(len(mus) - 1))
1154-
metricGrowth, profileGrowth, n, _ := testcase(true, stk, workers, fn)(t)
1167+
metricGrowth, profileGrowth, n, _ := testcase(true, stks, workers, fn)(t)
11551168

11561169
if have, want := metricGrowth, delay.Seconds()*float64(len(mus)); have < want {
11571170
// The test imposes a delay with usleep, verified with calls to
@@ -1175,7 +1188,7 @@ func TestRuntimeLockMetricsAndProfile(t *testing.T) {
11751188
defer runtime.SetMutexProfileFraction(old)
11761189

11771190
needContention.Store(int64(len(mus) - 1))
1178-
metricGrowth, profileGrowth, n, _ := testcase(true, stk, workers, fn)(t)
1191+
metricGrowth, profileGrowth, n, _ := testcase(true, stks, workers, fn)(t)
11791192

11801193
// With 100 trials and profile fraction of 2, we expect to capture
11811194
// 50 samples. Allow the test to pass if we get at least 20 samples;
@@ -1231,19 +1244,32 @@ func TestRuntimeLockMetricsAndProfile(t *testing.T) {
12311244
return true
12321245
}
12331246

1234-
stk := []string{
1235-
"runtime.unlock",
1236-
"runtime.semrelease1",
1237-
"runtime_test.TestRuntimeLockMetricsAndProfile.func6.1",
1238-
"runtime_test.(*contentionWorker).run",
1247+
stks := [][]string{
1248+
{
1249+
"runtime.unlock",
1250+
"runtime.semrelease1",
1251+
"runtime_test.TestRuntimeLockMetricsAndProfile.func6.1",
1252+
"runtime_test.(*contentionWorker).run",
1253+
},
1254+
{
1255+
"runtime.unlock",
1256+
"runtime.semacquire1",
1257+
"runtime.semacquire",
1258+
"runtime_test.TestRuntimeLockMetricsAndProfile.func6.1",
1259+
"runtime_test.(*contentionWorker).run",
1260+
},
12391261
}
12401262

12411263
// Verify that we get call stack we expect, with anything more than zero
12421264
// cycles / zero samples. The duration of each contention event is too
12431265
// small relative to the expected overhead for us to verify its value
12441266
// more directly. Leave that to the explicit lock/unlock test.
12451267

1246-
testcase(false, stk, workers, fn)(t)
1268+
testcase(false, stks, workers, fn)(t)
1269+
1270+
if remaining := tries.Load(); remaining >= 0 {
1271+
t.Logf("finished test early (%d tries remaining)", remaining)
1272+
}
12471273
})
12481274
}
12491275

0 commit comments

Comments
 (0)