Test failure in test/finprofiled.go --- integer divide by zero

[RuinanSun]

What version of Go are you using (go version)?

$ go version
go version devel go1.22-12051f7d95 Wed Nov 15 04:10:05 2023 +0000 linux/arm64

Does this issue reproduce with the latest release?

What operating system and processor architecture are you using (go env)?

go env Output

$ go env
GO111MODULE=''
GOARCH='arm64'
GOBIN=''
GOCACHE='/home/ruisun01/.cache/go-build'
GOENV='/home/ruisun01/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='arm64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/home/ruisun01/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/ruisun01/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/home/ruisun01/work/aarch64/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/home/ruisun01/work/aarch64/go/pkg/tool/linux_arm64'
GOVCS=''
GOVERSION='devel go1.22-12051f7d95 Wed Nov 15 04:10:05 2023 +0000'
GCCGO='gccgo'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/home/ruisun01/work/aarch64/go/src/go.mod'
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 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build3780787530=/tmp/go-build -gno-record-gcc-switches'

What did you do?

run all.bash, or run go test cmd/internal/testdir -run Test/finprofiled.go

What did you expect to see?

All tests pass

What did you see instead?

--- FAIL: Test (0.08s)
    --- FAIL: Test/finprofiled.go (2.13s)
        testdir_test.go:142: exit status 2
            panic: runtime error: integer divide by zero

            goroutine 1 [running]:
            main.main()
            	/home/ruisun01/work/aarch64/go/test/finprofiled.go:60 +0x2d4

FAIL
FAIL	cmd/internal/testdir	2.240s
FAIL

Some thoughts:

I'm not very familiar with GC and memory profiler, but in finprofiled.go:60, the code truly does not check the value of nobj:

// finprofiled.go
...
for _, p := range prof {
	bytes := p.AllocBytes - p.FreeBytes
	nobj := p.AllocObjects - p.FreeObjects
	// println("bytes: ", bytes, "\t\tnobj: ", nobj)
	size := bytes / nobj // can nobj be zero?
	if size == tinyBlockSize {
		totalBytes += bytes
	}
}
...

I try to reproduce it in other machines(x86, darwin/arm64) but it only occurs on my arm64 container. So I have to say I can't make sure whether it's caused by my container or it's just a simple bug. Here are some info I just collected:

• I git bisect and it points at CL 538217

• Here is the log if I uncomment the println:

--- FAIL: Test (0.05s)
    --- FAIL: Test/finprofiled.go (2.89s)
        testdir_test.go:142: exit status 2
            bytes:  24 		nobj:  3
            bytes:  16 		nobj:  2
            bytes:  80 		nobj:  1
            bytes:  16 		nobj:  1
            bytes:  576 		nobj:  6
            bytes:  416 		nobj:  1
            bytes:  416 		nobj:  1
            bytes:  1400 		nobj:  1
            bytes:  6240 		nobj:  15
            bytes:  6240 		nobj:  15
            bytes:  21000 		nobj:  15
            bytes:  4194320 		nobj:  262145
            bytes:  5824 		nobj:  14
            bytes:  5824 		nobj:  14
            bytes:  19600 		nobj:  14
            bytes:  2296 		nobj:  1
            bytes:  -8 		nobj:  0 # Is that valid?
            panic: runtime error: integer divide by zero

            goroutine 1 [running]:
            main.main()
            	/home/ruisun01/work/aarch64/go/test/finprofiled.go:61 +0x340

FAIL
FAIL	cmd/internal/testdir	2.947s
FAIL

[bcmills]

I git bisect and it points at CL 538217

Marking as release-blocker since that is a significant change during the Go 1.22 development cycle.

[mknyszek]

This is odd. The negative bytes suggests an accounting error for the alloc header. I'll take a look.

[mknyszek]

OK there's a fairly clear (to me) accounting error for memory profiles specifically. That explains the -8 and it's easy to fix. However, I do think that this code can correctly end up having 0 objects for an individual memprofile record (which represents allocations for a particular stack trace), so there's an issue with the test.

[gopherbot]

Change https://go.dev/cl/542735 mentions this issue: runtime: use span.elemsize for accounting in mallocgc

[gopherbot]

Change https://go.dev/cl/542736 mentions this issue: test: ignore MemProfileRecords with no live objects in finprofiled.go