cmd/trace/v2: pprof profiles always empty

[klauspost]

Go version

go version go1.22.4 windows/amd64

Output of go env in your module/workspace:

λ go env
set GO111MODULE=
set GOARCH=amd64
set GOBIN=
set GOCACHE=e:\temp\gocache
set GOENV=C:\Users\klaus\AppData\Roaming\go\env
set GOEXE=.exe
set GOEXPERIMENT=
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=e:\gopath\pkg\mod
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=e:\gopath
set GOPRIVATE=
set GOPROXY=https://goproxy.io,https://proxy.golang.org,direct
set GOROOT=C:\go
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLCHAIN=auto
set GOTOOLDIR=C:\go\pkg\tool\windows_amd64
set GOVCS=
set GOVERSION=go1.22.4
set GCCGO=gccgo
set GOAMD64=v1
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=c:\go\src\cmd\go.mod
set GOWORK=
set CGO_CFLAGS=-O2 -g
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-O2 -g
set CGO_FFLAGS=-O2 -g
set CGO_LDFLAGS=-O2 -g
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=e:\temp\wintemp\go-build3441812285=/tmp/go-build -gno-record-gcc-switches

What did you do?

Using go tool trace profile.trace (this is a v2 profile - the -pprof parameter is ignored)

Using sample profile: https://download.klauspost.com/profile.trace.gz

λ go tool trace profile.trace
2024/07/22 14:14:48 Preparing trace for viewer...
2024/07/22 14:14:53 Splitting trace for viewer...
2024/07/22 14:15:23 Opening browser. Trace viewer is listening on http://127.0.0.1:64503

Click links or download with:

curl http://127.0.0.1:64503/io?raw=1 -o io.pprof
curl http://127.0.0.1:64503/block?raw=1 -o block.pprof
curl http://127.0.0.1:64503/syscall?raw=1 -o syscall.pprof
curl http://127.0.0.1:64503/sched?raw=1 -o sched.pprof

What did you see happen?

Empty profiles:

λ ls -l
total 4
-rw-r--r-- 1 klaus 197121 90 Jul 22 14:19 block.pprof
-rw-r--r-- 1 klaus 197121 90 Jul 22 14:19 io.pprof
-rw-r--r-- 1 klaus 197121 90 Jul 22 14:19 sched.pprof
-rw-r--r-- 1 klaus 197121 90 Jul 22 14:19 syscall.pprof

What did you expect to see?

The advertised profiles.

[klauspost]

Here is the output, just for completeness - output.zip

[gabyhelp]

Related Issues and Documentation

• cmd/trace: always opening browser, not printing profile #66782 (closed)
• pprof: go tool pprof cannot read the pprof file normally #66227 (closed)
• cmd/pprof: wsl cpu profiles are empty #32824 (closed)
• runtime/pprof: go test report empty cpuprofile file on wsl #27115 (closed)
• runtime/pprof: WriteHeapProfile example is not strictly equivalent to testing memprofile #65328
• runtime/pprof: heap profile is blank on go1.23rc1 (go1.22.4 was ok) #68136 (closed)
• pprof: source view is always blank at tip (due to upstream pprof bug) #45786 (closed)
• cmd/pprof: panics if profile is not found #67626 (closed)
• cmd/pprof: pprof create profile directory under the root dir, not %USERPROFILE% on windows #18864 (closed)
• runtime/pprof: system information in output #59307

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

[klauspost]

It seems like pprofOverlappingDuration always returns 0. That is as far as I can go into debugging and still make sense of what is happening.

Replacing pprofOverlappingDuration with return sample.duration() makes it return something, but I don't know enough about the internals to tell how valid it is.

[dmitshur]

CC @golang/runtime via owners.

[mknyszek]

Hm, I'll look into this. I feel like I may have fixed a bug related to this recently -- I will try to dig it up.

Do you have the same problem with the Go 1.23rc2 toolchain? (Using the trace tool from that toolchain, I mean.)

[rhysh]

This looks like what CL 578356 and CL 578318 fixed, for #66782. Checking that go1.23rc2 works should confirm.

Those CLs should probably get backported.

[mknyszek]

Thanks @rhysh! That's exactly what I had in mind. Agreed on backporting.

[rhysh]

@gopherbot please backport to Go 1.22. The impact is limited to local runs of go tool trace, but there's no workaround. And since the change only affects go tool trace, it's relatively low risk.

[gopherbot]

Backport issue(s) opened: #68546 (for 1.22).

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/600255 mentions this issue: cmd/trace/v2: handle the -pprof flag

[gopherbot]

Change https://go.dev/cl/600275 mentions this issue: cmd/trace/v2: make the -pprof actually useful

[dmitshur]

Closing in favor of #66782, since this is already fixed in Go 1.23.

(CL 600275 included "Fixes #68542" but cherry-pick CLs only close cherry-pick issues automatically, not regular issues.)