go icon indicating copy to clipboard operation
go copied to clipboard

runtime/pprof: heap profile is blank on go1.23rc1 (go1.22.4 was ok)

Open S-YOU opened this issue 1 year ago • 11 comments

Go version

go1.23rc1

Output of go env in your module/workspace:

GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/home/dummy/.cache/go-build'
GOENV='/home/dummy/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS='-mod=readonly'
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/home/dummy/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/dummy/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/opt/go'
GOSUMDB='off'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/opt/go/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.23rc1'
GODEBUG=''
GOTELEMETRY='local'
GOTELEMETRYDIR='/home/dummy/.config/go/telemetry'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/dev/null'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build2527459232=/tmp/go-build -gno-record-gcc-switches'

What did you do?

Taking heap profile for my application using heap profile from runtime package

What did you see happen?

heap profile shows nothing (it was ok in go1.22.4)

What did you expect to see?

show something in heap profile

S-YOU avatar Jun 23 '24 09:06 S-YOU

Right now this issue isn't very actionable with the lack of information: what were the exact steps you took to generate the profile? what does blank mean? do you have a standalone reproducer? can we see the profile?

seankhliao avatar Jun 23 '24 09:06 seankhliao

I can share profile for go1.23rc1, here it is. it is only 231 bytes @seankhliao heap-20240623_094946.out.zip

% xxd heap-20240623_094946.out
00000000: 1f8b 0800 0000 0000 04ff 3c8a 314e c340  ..........<.1N.@
00000010: 1045 b1e3 0d8b a3a0 2d90 b0dc 203a 7723  .E......-... :w#
00000020: cd29 3803 5184 d6cb 0a8c d6bb 91c7 8994  .)8.Q...........
00000030: 6e6a c421 5222 7112 4493 863e 151d 0740  nj.!R"q.D..>...@
00000040: 1446 b645 a699 f7ff 7fb7 898c 549c 2672  .F.E........T.&r
00000050: a292 3491 62e0 e9c0 a72a be79 ff7c fe79  ..4.b....*.y.|.y
00000060: 79fd fabe cccf 65a4 9839 ce98 0fa2 90f9  y.....e..9......
00000070: 858c 15ef f66f 1fdd 55c6 877d ff8b b33c  .....o..U..}...<
00000080: 9793 defa edfa 8b32 defd 6391 e209 0a5a  .......2..c....Z
00000090: 6963 5194 dbd6 12ce b573 c1dc 85f2 c99a  icQ......s......
000000a0: 9650 98b0 f62d cef4 d08e e6bc f26b b247  .P...-.......k.G
000000b0: 6536 c671 bb86 c750 5bf0 bab6 d0d8 5580  e6.q...P[.....U.
000000c0: 8700 d418 68a0 ac3c d4ba f238 5d6c ee29  ....h..<...8]l.)
000000d0: 2c31 5d6c 684b 463b b7fc 0b00 00ff ff77  ,1]lhKF;.......w
000000e0: 6fcf 84f0 0000 00                        o......

S-YOU avatar Jun 23 '24 09:06 S-YOU

How was it created?

seankhliao avatar Jun 23 '24 10:06 seankhliao

How was it created?

by calling runtime/pprof.writeHeap directly from my application @seankhliao

S-YOU avatar Jun 23 '24 10:06 S-YOU

okay, when I change profilerecord.StackRecord back to runtime.StackRecord in some places, it shows something. Might be releated to that fixed 32 depth (array) to 128 (slice) stuff.

image

S-YOU avatar Jun 23 '24 11:06 S-YOU

Note: I could only get this to reproduce on very simple programs, doing anything more such as dual writing through pprof.Lookup("heap").WriteTo eliminated the issue.

seankhliao avatar Jun 24 '24 12:06 seankhliao

Why is the profile entirely "<unknown>"? What is your total heap size? Can you post the non-empty profile as well?

rsc avatar Jun 28 '24 20:06 rsc

Why is the profile entirely "<unknown>"?

<unknown> is because of my partial changes as I mentioned here. I didn't touch *goroutineProfileWithLabels part, so, I guess names are cannot loaded properly. It do show source file locations in source, so <unknown> part is not the problem I believe. @rsc

okay, when I change profilerecord.StackRecord back to runtime.StackRecord in some places, it shows something.

I am not sure profile from modified version of go1.23rc1 or go1.22.4 benefit anything here.

S-YOU avatar Jun 29 '24 07:06 S-YOU

btw, this is the temporary patch I applied to go1.23rc1 to get previous behavior back for pprof and also temporarily modified goroutineProfileWithLabelsConcurrent to get unknowns labels to proper one. Some might not related, but this is what I have now.

go-1.23rc1-pprof-tmp.patch.zip

S-YOU avatar Jun 29 '24 07:06 S-YOU

okay, seems like I understand the issue and what was changed in go1.23rc1

when I put _ = pprof.Lookup("heap") in program startup, the issue seems to be resolved and profile is not blank anymore.

you may close the issue, if it is working as expected. @rsc @seankhliao

S-YOU avatar Jun 29 '24 08:06 S-YOU

This is actually a real bug. Thanks @S-YOU for reporting. I'll send a fix soon.

cherrymui avatar Jul 03 '24 17:07 cherrymui

Change https://go.dev/cl/596538 mentions this issue: cmd/link: don't disable memory profiling when pprof.WriteHeapProfile is used

gopherbot avatar Jul 03 '24 18:07 gopherbot

Thank you very much the for the fix @cherrymui, didn't realize that its been optimized out.

S-YOU avatar Jul 07 '24 08:07 S-YOU