runtime: MutexProfile missing root frames in go1.23

[felixge]

Go version

go1.23.1

What did you do?

Print the stack traces of a runtime.MutexProfile() using the code below.

package main

import (
	"fmt"
	"runtime"
	"sync"
	"time"
)

func main() {
	produceMutexContention()
	printMutexProfile()
}

func produceMutexContention() {
	runtime.SetMutexProfileFraction(1)
	var mu sync.Mutex
	done := make(chan struct{})
	defer close(done)
	for range runtime.GOMAXPROCS(-1) * 2 {
		go func() {
			for finish := false; !finish; {
				mu.Lock()
				select {
				case <-done:
					finish = true
				default:
					time.Sleep(time.Millisecond)
				}
				mu.Unlock()
			}
		}()
	}
	time.Sleep(time.Second)
}

func printMutexProfile() {
	var records []runtime.BlockProfileRecord
	for {
		n, ok := runtime.MutexProfile(records)
		if ok {
			records = records[:n]
			break
		}
		records = make([]runtime.BlockProfileRecord, n*2)
	}

	for _, r := range records {
		var funcs []string
		frames := runtime.CallersFrames(r.Stack())
		for {
			frame, more := frames.Next()
			funcs = append(funcs, frame.Function)
			if !more {
				break
			}
		}
		fmt.Printf("%#v\n", funcs)
	}
}

What did you see happen?

go1.23.1 produces the following output:

[]string{"sync.(*Mutex).Unlock", "main.produceMutexContention.func1"}
[]string{""}

What did you expect to see?

The same output as go1.22.7:

[]string{"sync.(*Mutex).Unlock", "main.produceMutexContention.func1", "runtime.goexit"}
[]string{"runtime._LostContendedRuntimeLock"}

Additional Notes

This problem only happens when using the runtime.MutexProfile API. runtime/pprof output is not impacted.

I have submitted https://go-review.googlesource.com/c/go/+/611615 to fix this problem.

[gabyhelp]

Related Issues and Documentation

• runtime: MutexProfile has multiple records with equal stack #67548 (closed)
• runtime: contended mutex profiling doesn't work for sync.RWMutex #18496 (closed)
• runtime: correct attribution of internal mutex contention #66999
• Package pprof > type Profile ¶ > Mutex profile
• RWMutex.Unlock() appearing in mutex contention profiles #19102 (closed)
• runtime/pprof: change in behavior between Go 1.13 and 1.14 #36874 (closed)
• runtime/pprof: block and mutex profile stacks sometimes have "gowrap" root frames #69294
• runtime/pprof: blockprofile test fails in VMs #7696 (closed)
• sync: mutex profiling information is confusing (wrong?) for mutexes with >2 contenders #24877
• runtime: ~5% regression in ParallelizeUntil/pieces:1000,workers:10,chunkSize:1-8 sec/op at 450ecbe #64455

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

[gopherbot]

Change https://go.dev/cl/611615 mentions this issue: runtime: fix MutexProfile missing root frames

[timothy-king]

CC @golang/runtime, @mknyszek, @prattmic.

[mknyszek]

Ping @felixge @nsrip-dd re: @cagedmantis's question from #69243. Does this need a backport as well? Thanks.

[nsrip-dd]

@mknyszek I'd say yes, since this bug causes mutex profiles obtained via runtime.MutexProfile to miss information, specifically runtime._LostContendedRuntimeLock records will have no stack.

[felixge]

@gopherbot Please backport to 1.23. This is a regression in mutex profiles with no workaround.

(not sure if this works, i might not have permissions)

[gopherbot]

Backport issue(s) opened: #69865 (for 1.23).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://go.dev/wiki/MinorReleases.

[gopherbot]

Change https://go.dev/cl/621276 mentions this issue: runtime: fix MutexProfile missing root frames