obs: export metrics about Go GC Assist work

[nvanbenschoten]

CockroachDB currently exports some timeseries metrics about the Go runtime memory GC:

• sys.gc.pause.percent: "Current GC pause percentage"
• sys.gc.pause.ns: "Total GC pause"
• sys.gc.count: "Total number of GC runs"

These metrics are computed using runtime.ReadGCStats. They are useful to understand how long the Go GC is stopping the world ("pause" refers to STW work, not background work).

However, GO GC has other costs beyond its STW sweep termination and mark termination phases. In general, the concurrent mark and scan phase can be run without pushing back on foreground goroutines. However, when goroutines are allocating memory faster than GC can clean up (either because of significant memory allocation, slow GC, or both), GC work can be pushed back on foreground goroutines in line with their heap allocations. This is known as "GC Assist".

We've seen in cases like this one that GC assist can lead to large spikes in latency that are difficult to understand using other observability tools.

We should find a way to expose this information. Unfortunately, this is not exported by the go runtime, except through the GODEBUG=gctrace tooling. We may need to patch the runtime or upstream a fix to get at the information programmatically.

Jira issue: CRDB-19718

Epic CRDB-34227

[nvanbenschoten]

golang/go#55159 is a start here. If we can land that upstream, we can define a timeseries metric over this value. Ideally, we'd also be able to set up some alerting on it to detect when goroutines are over-assisting (e.g. normalized_rate(assist_ns) > 0.05).

[nvanbenschoten]

It turns out that https://go-review.googlesource.com/c/go/+/404307 landed 3 days ago and added a new "/cpu/classes/gc/mark/assist:cpu-seconds" metric (among others) to the https://pkg.go.dev/runtime/metrics package. This contains the same information I was trying to expose in golang/go#55159. So we'll need to wait for Go 1.20 and can then integrate that into our RuntimeStatSampler logic.

That may be a good time to replace calls to debug.ReadGCStats and runtime.ReadMemStats with use of the new runtime/metrics package, which is also mentioned in #87823.

[nvanbenschoten]

That may be a good time to replace calls to debug.ReadGCStats and runtime.ReadMemStats with use of the new runtime/metrics package, which is also mentioned in #87823.

Doing so will avoid the stop-the-world pause during calls to runtime.ReadMemStats. These pauses take about 1.5ms, and occur every 10s.

[nvanbenschoten]

That may be a good time to replace calls to debug.ReadGCStats and runtime.ReadMemStats with use of the new runtime/metrics package, which is also mentioned in #87823.

@lyang24 determined that the mapping for this will look like:

GoAllocBytes:      ms.HeapAlloc => /gc/heap/allocs:bytes
HeapFragmentBytes: ms.HeapInuse - ms.HeapAlloc => /memory/classes/heap/unused:bytes
HeapReservedBytes: ms.HeapIdle - ms.HeapReleased => /memory/classes/heap/free:bytes
HeapReleasedBytes: ms.HeapReleased => /memory/classes/heap/released:bytes
MemStackSysBytes:  ms.StackSys => /memory/classes/heap/stacks:bytes
goTotal := ms.Sys - ms.HeapReleased => /memory/classes/total:bytes

[nvanbenschoten]

That may be a good time to replace calls to debug.ReadGCStats and runtime.ReadMemStats with use of the new runtime/metrics package, which is also mentioned in #87823.

I've extracted this into #119461 and #119462.

[lyang24]

That may be a good time to replace calls to debug.ReadGCStats and runtime.ReadMemStats with use of the new runtime/metrics package, which is also mentioned in #87823.

@lyang24 determined that the mapping for this will look like:

GoAllocBytes:      ms.HeapAlloc => /gc/heap/allocs:bytes
HeapFragmentBytes: ms.HeapInuse - ms.HeapAlloc => /memory/classes/heap/unused:bytes
HeapReservedBytes: ms.HeapIdle - ms.HeapReleased => /memory/classes/heap/free:bytes
HeapReleasedBytes: ms.HeapReleased => /memory/classes/heap/released:bytes
MemStackSysBytes:  ms.StackSys => /memory/classes/heap/stacks:bytes
goTotal := ms.Sys - ms.HeapReleased => /memory/classes/total:bytes

I made a mistake on GoAllocBytes after testing need to update mapping to
GoAllocBytes: ms.HeapAlloc => /memory/classes/heap/objects:bytes
"Memory occupied by live objects and dead objects that have not
yet been marked free by the garbage collector."

/gc/heap/allocs:bytes is the total allocated bytes and this number will not decrease on release

[andrewbaptist]

A few recent support escalations would have been much easier to debug with this information exposed.