runtime/metrics: /memory/classes/heap/unused:bytes spikes about go

[mknyszek]

I think I found the bug. The span can be freed (and the "bytes in heap" stats can be updated) before we update the object stats for large objects on sweep. The subtraction assumes that object stats are always handled before the "bytes in heap" stat.

[felixge]

I've checked and think I can rule out arena usage. There are no search hits for arena imports in our mono-repo, and we're seeing this issue across most of our services.

Any other ideas for things we could do to help debug this? Do you have a chance to see if the issue happens with Google's fleet? It's possible we're doing something weird, but I'm not sure what 🤔 . This is the only memory metric that we see behave oddly like this.

[mknyszek]

Hm... those differences are so large (300+ MiB??) that it doesn't seem like a situation where we're transiently racy in some corner case (as is the usual case for accounting bugs). It's a bit difficult to explain this.

This is a shot in the dark, but is it possible these services are using GOEXPERIMENT=arenas? That's maybe the one area where I could see both (1) skew this large and (2) accounting bugs still lurk, because it's used less widely.

[gopherbot]

Change https://go.dev/cl/583380 mentions this issue: runtime: update large object stats before freeSpan in sweep

[mknyszek]

@gopherbot Please open backport issues for Go 1.21 and Go 1.22.

This issue can cause spurious overflow in runtime metrics with no workaround.

[gopherbot]

Backport issue(s) opened: #67187 (for 1.21), #67188 (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.

[mknyszek]

Reproducer:

package main

import (
	"runtime/metrics"
)

var sink any

func main() {
	go func() {
		s := []metrics.Sample{
			{Name: "/memory/classes/heap/unused:bytes"},
		}
		for {
			metrics.Read(s)
			val := s[0].Value.Uint64()
			if val > 1<<40 {
				panic("overflow")
			}
		}
	}()
	for {
		sink = make([]byte, 10<<20)
		sink = nil
	}
}

[gopherbot]

Change https://go.dev/cl/584337 mentions this issue: [relase-branch.go1.21] runtime: update large object stats before freeSpan in sweep

[gopherbot]

Change https://go.dev/cl/584339 mentions this issue: [relase-branch.go1.22] runtime: update large object stats before freeSpan in sweep