aboutsummaryrefslogtreecommitdiff
path: root/src/runtime/pprof
diff options
context:
space:
mode:
Diffstat (limited to 'src/runtime/pprof')
-rw-r--r--src/runtime/pprof/pprof.go23
-rw-r--r--src/runtime/pprof/pprof_test.go164
2 files changed, 185 insertions, 2 deletions
diff --git a/src/runtime/pprof/pprof.go b/src/runtime/pprof/pprof.go
index d3af5bba91..4b7a9f63c6 100644
--- a/src/runtime/pprof/pprof.go
+++ b/src/runtime/pprof/pprof.go
@@ -404,6 +404,25 @@ type countProfile interface {
Label(i int) *labelMap
}
+// expandInlinedFrames copies the call stack from pcs into dst, expanding any
+// PCs corresponding to inlined calls into the corresponding PCs for the inlined
+// functions. Returns the number of frames copied to dst.
+func expandInlinedFrames(dst, pcs []uintptr) int {
+ cf := runtime.CallersFrames(pcs)
+ var n int
+ for n < len(dst) {
+ f, more := cf.Next()
+ // f.PC is a "call PC", but later consumers will expect
+ // "return PCs"
+ dst[n] = f.PC + 1
+ n++
+ if !more {
+ break
+ }
+ }
+ return n
+}
+
// printCountCycleProfile outputs block profile records (for block or mutex profiles)
// as the pprof-proto format output. Translations from cycle count to time duration
// are done because The proto expects count and time (nanoseconds) instead of count
@@ -426,7 +445,7 @@ func printCountCycleProfile(w io.Writer, countName, cycleName string, records []
values[1] = int64(float64(r.Cycles) / cpuGHz)
// For count profiles, all stack addresses are
// return PCs, which is what appendLocsForStack expects.
- n := pprof_fpunwindExpand(expandedStack[:], r.Stack)
+ n := expandInlinedFrames(expandedStack, r.Stack)
locs = b.appendLocsForStack(locs[:0], expandedStack[:n])
b.pbSample(values, locs, nil)
}
@@ -935,7 +954,7 @@ func writeProfileInternal(w io.Writer, debug int, name string, runtimeProfile fu
for i := range p {
r := &p[i]
fmt.Fprintf(w, "%v %v @", r.Cycles, r.Count)
- n := pprof_fpunwindExpand(expandedStack, r.Stack)
+ n := expandInlinedFrames(expandedStack, r.Stack)
stack := expandedStack[:n]
for _, pc := range stack {
fmt.Fprintf(w, " %#x", pc)
diff --git a/src/runtime/pprof/pprof_test.go b/src/runtime/pprof/pprof_test.go
index 09abbb31ae..30ef50b1c0 100644
--- a/src/runtime/pprof/pprof_test.go
+++ b/src/runtime/pprof/pprof_test.go
@@ -21,6 +21,7 @@ import (
"regexp"
"runtime"
"runtime/debug"
+ "strconv"
"strings"
"sync"
"sync/atomic"
@@ -2578,3 +2579,166 @@ func produceProfileEvents(t *testing.T, depth int) {
runtime.GC()
goroutineDeep(t, depth-4) // -4 for produceProfileEvents, **, chanrecv1, chanrev, gopark
}
+
+func getProfileStacks(collect func([]runtime.BlockProfileRecord) (int, bool), fileLine bool) []string {
+ var n int
+ var ok bool
+ var p []runtime.BlockProfileRecord
+ for {
+ p = make([]runtime.BlockProfileRecord, n)
+ n, ok = collect(p)
+ if ok {
+ p = p[:n]
+ break
+ }
+ }
+ var stacks []string
+ for _, r := range p {
+ var stack strings.Builder
+ for i, pc := range r.Stack() {
+ if i > 0 {
+ stack.WriteByte('\n')
+ }
+ // Use FuncForPC instead of CallersFrames,
+ // because we want to see the info for exactly
+ // the PCs returned by the mutex profile to
+ // ensure inlined calls have already been properly
+ // expanded.
+ f := runtime.FuncForPC(pc - 1)
+ stack.WriteString(f.Name())
+ if fileLine {
+ stack.WriteByte(' ')
+ file, line := f.FileLine(pc - 1)
+ stack.WriteString(file)
+ stack.WriteByte(':')
+ stack.WriteString(strconv.Itoa(line))
+ }
+ }
+ stacks = append(stacks, stack.String())
+ }
+ return stacks
+}
+
+func TestMutexBlockFullAggregation(t *testing.T) {
+ // This regression test is adapted from
+ // https://github.com/grafana/pyroscope-go/issues/103,
+ // authored by Tolya Korniltsev
+
+ var m sync.Mutex
+
+ prev := runtime.SetMutexProfileFraction(-1)
+ defer runtime.SetMutexProfileFraction(prev)
+
+ const fraction = 1
+ const iters = 100
+ const workers = 2
+
+ runtime.SetMutexProfileFraction(fraction)
+ runtime.SetBlockProfileRate(1)
+ defer runtime.SetBlockProfileRate(0)
+
+ wg := sync.WaitGroup{}
+ wg.Add(workers)
+ for j := 0; j < workers; j++ {
+ go func() {
+ for i := 0; i < iters; i++ {
+ m.Lock()
+ // Wait at least 1 millisecond to pass the
+ // starvation threshold for the mutex
+ time.Sleep(time.Millisecond)
+ m.Unlock()
+ }
+ wg.Done()
+ }()
+ }
+ wg.Wait()
+
+ assertNoDuplicates := func(name string, collect func([]runtime.BlockProfileRecord) (int, bool)) {
+ stacks := getProfileStacks(collect, true)
+ seen := make(map[string]struct{})
+ for _, s := range stacks {
+ if _, ok := seen[s]; ok {
+ t.Errorf("saw duplicate entry in %s profile with stack:\n%s", name, s)
+ }
+ seen[s] = struct{}{}
+ }
+ if len(seen) == 0 {
+ t.Errorf("did not see any samples in %s profile for this test", name)
+ }
+ }
+ t.Run("mutex", func(t *testing.T) {
+ assertNoDuplicates("mutex", runtime.MutexProfile)
+ })
+ t.Run("block", func(t *testing.T) {
+ assertNoDuplicates("block", runtime.BlockProfile)
+ })
+}
+
+func inlineA(mu *sync.Mutex, wg *sync.WaitGroup) { inlineB(mu, wg) }
+func inlineB(mu *sync.Mutex, wg *sync.WaitGroup) { inlineC(mu, wg) }
+func inlineC(mu *sync.Mutex, wg *sync.WaitGroup) {
+ defer wg.Done()
+ mu.Lock()
+ mu.Unlock()
+}
+
+func inlineD(mu *sync.Mutex, wg *sync.WaitGroup) { inlineE(mu, wg) }
+func inlineE(mu *sync.Mutex, wg *sync.WaitGroup) { inlineF(mu, wg) }
+func inlineF(mu *sync.Mutex, wg *sync.WaitGroup) {
+ defer wg.Done()
+ mu.Unlock()
+}
+
+func TestBlockMutexProfileInlineExpansion(t *testing.T) {
+ runtime.SetBlockProfileRate(1)
+ defer runtime.SetBlockProfileRate(0)
+ prev := runtime.SetMutexProfileFraction(1)
+ defer runtime.SetMutexProfileFraction(prev)
+
+ var mu sync.Mutex
+ var wg sync.WaitGroup
+ wg.Add(2)
+ mu.Lock()
+ go inlineA(&mu, &wg)
+ awaitBlockedGoroutine(t, "sync.Mutex.Lock", "inlineC", 1)
+ // inlineD will unblock inlineA
+ go inlineD(&mu, &wg)
+ wg.Wait()
+
+ tcs := []struct {
+ Name string
+ Collect func([]runtime.BlockProfileRecord) (int, bool)
+ SubStack string
+ }{
+ {
+ Name: "mutex",
+ Collect: runtime.MutexProfile,
+ SubStack: `sync.(*Mutex).Unlock
+runtime/pprof.inlineF
+runtime/pprof.inlineE
+runtime/pprof.inlineD`,
+ },
+ {
+ Name: "block",
+ Collect: runtime.BlockProfile,
+ SubStack: `sync.(*Mutex).Lock
+runtime/pprof.inlineC
+runtime/pprof.inlineB
+runtime/pprof.inlineA`,
+ },
+ }
+
+ for _, tc := range tcs {
+ t.Run(tc.Name, func(t *testing.T) {
+ stacks := getProfileStacks(tc.Collect, false)
+ for _, s := range stacks {
+ if strings.Contains(s, tc.SubStack) {
+ return
+ }
+ }
+ t.Error("did not see expected stack")
+ t.Logf("wanted:\n%s", tc.SubStack)
+ t.Logf("got: %s", stacks)
+ })
+ }
+}