runtime/pprof: block/mutex profile stacks can sometimes miss leaf frames

[nsrip-dd]

Go version

go version go1.23.1 darwin/arm64

Output of go env in your module/workspace:

n/a

What did you do?

Built this program with PGO and ran it:

package main

import (
	"os"
	"runtime"
	"runtime/pprof"
)

func main() {
	runtime.SetBlockProfileRate(1)
	ch := make(chan struct{})
	go func() {
		close(ch)
	}()
	<-ch
	pprof.Lookup("block").WriteTo(os.Stdout, 1)
}

What did you see happen?

If I build with PGO using a profile where runtime.blockevent is hot, then I see this output:

--- contention:
cycles/second=999458200
97416 1 @ 0x4cd357 0x438c4b 0x4709a1
#	0x4cd356	main.main+0x76		/home/junk/simple.go:17
#	0x438c4a	runtime.main+0x28a	/usr/local/go/src/runtime/proc.go:272

Example program which generates such a CPU profile:

package main

import (
	"os"
	"runtime"
	"runtime/pprof"
	"time"
	_ "unsafe"
)

//go:linkname blockevent runtime.blockevent
func blockevent(cycles int64, skip int)

func main() {
	runtime.SetBlockProfileRate(1)
	pprof.StartCPUProfile(os.Stdout)
	defer pprof.StopCPUProfile()
	now := time.Now()
	for time.Since(now) < 5*time.Second {
		for i := 0; i < 100000; i++ {
			blockevent(1, 1)
		}
	}
}

What did you expect to see?

I expected to see chanrecv1 in the root frame:

--- contention:
cycles/second=999008970
54083 1 @ 0x406312 0x4cd357 0x438c4b 0x4709a1
#	0x406311	runtime.chanrecv1+0x11	/usr/local/go/src/runtime/chan.go:489
#	0x4cd356	main.main+0x76		/home/junk/simple.go:17
#	0x438c4a	runtime.main+0x28a	/usr/local/go/src/runtime/proc.go:272

I see that if I run the program with frame pointer unwinding disabled (GODEBUG=tracefpunwindoff=1) or if I run it with Go 1.22.

The problem is that if runtime.saveblockevent is inlined into runtime.blockevent, then getfp() will return one of runtime.saveblockevent's callers frame pointers here, and runtime.fpTracebackPartialExpand will start frame pointer unwinding from the wrong frame, making the skip values incorrect. Depending on how much inlining there is, we might see even more missing frames.

[gabyhelp]

Related Issues and Documentation

• runtime/pprof: block and mutex profile stacks sometimes have "gowrap" root frames #69294
• runtime: MutexProfile missing root frames in go1.23 #69335 (closed)
• runtime/pprof: inline frames may not use combined location #37446 (closed)
• runtime/pprof: collecting a CPU profile takes ~200ms of wall time #63043
• runtime/pprof: under-samples all work when runtime creates threads #40963 (closed)
• runtime/pprof: collecting mutex or block profiles add ~100ms of wall time #63078 (closed)
• runtime/pprof: under-samples work on short-lived threads #40435 (closed)
• runtime: framepointer-based stack unwinding omits memmove's callee #58835
• runtime: frame pointer unwinding can fail on system goroutines #63630
• runtime/pprof: Missing labels from goroutines stacks containing systemstack #48577 (closed)

_{(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)}

[gabyhelp]

Related Issues and Documentation

• runtime/pprof: block and mutex profile stacks sometimes have "gowrap" root frames #69294
• runtime: MutexProfile missing root frames in go1.23 #69335 (closed)
• runtime/pprof: inline frames may not use combined location #37446 (closed)
• runtime/pprof: collecting a CPU profile takes ~200ms of wall time #63043
• runtime/pprof: under-samples all work when runtime creates threads #40963 (closed)
• runtime/pprof: collecting mutex or block profiles add ~100ms of wall time #63078 (closed)
• runtime/pprof: under-samples work on short-lived threads #40435 (closed)
• runtime: framepointer-based stack unwinding omits memmove's callee #58835
• runtime: frame pointer unwinding can fail on system goroutines #63630
• runtime/pprof: Missing labels from goroutines stacks containing systemstack #48577 (closed)

_{(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)}

[mknyszek]

In triage, we don't think it's super important to show chanrecv1 here (the line in the user code should already point to the channel operation), but we understand the general concern about maintaining parity with older versions.