From: Michael Anthony Knyszek Date: Wed, 23 Jul 2025 03:09:27 +0000 (+0000) Subject: runtime/metrics: add cleanup and finalizer queue metrics X-Git-Url: http://www.git.cypherpunks.su/?a=commitdiff_plain;h=a4d99770c0e5f340d6d11d6353110413dc109138;p=gostls13.git runtime/metrics: add cleanup and finalizer queue metrics These metrics are useful for identifying finalizer and cleanup problems, namely slow finalizers and/or cleanups holding up the queue, which can lead to a memory leak. Fixes #72948. Change-Id: I1bb64a9ca751fcb462c96d986d0346e0c2894c95 Reviewed-on: https://go-review.googlesource.com/c/go/+/690396 Reviewed-by: Michael Pratt LUCI-TryBot-Result: Go LUCI Reviewed-by: Carlos Amedee Auto-Submit: Michael Knyszek --- diff --git a/src/runtime/metrics.go b/src/runtime/metrics.go index 48da745521..ef3782b783 100644 --- a/src/runtime/metrics.go +++ b/src/runtime/metrics.go @@ -169,6 +169,20 @@ func initMetrics() { out.scalar = float64bits(nsToSec(in.cpuStats.UserTime)) }, }, + "/gc/cleanups/executed:cleanups": { + deps: makeStatDepSet(finalStatsDep), + compute: func(in *statAggregate, out *metricValue) { + out.kind = metricKindUint64 + out.scalar = in.finalStats.cleanupsExecuted + }, + }, + "/gc/cleanups/queued:cleanups": { + deps: makeStatDepSet(finalStatsDep), + compute: func(in *statAggregate, out *metricValue) { + out.kind = metricKindUint64 + out.scalar = in.finalStats.cleanupsQueued + }, + }, "/gc/cycles/automatic:gc-cycles": { deps: makeStatDepSet(sysStatsDep), compute: func(in *statAggregate, out *metricValue) { @@ -190,6 +204,20 @@ func initMetrics() { out.scalar = in.sysStats.gcCyclesDone }, }, + "/gc/finalizers/executed:finalizers": { + deps: makeStatDepSet(finalStatsDep), + compute: func(in *statAggregate, out *metricValue) { + out.kind = metricKindUint64 + out.scalar = in.finalStats.finalizersExecuted + }, + }, + "/gc/finalizers/queued:finalizers": { + deps: makeStatDepSet(finalStatsDep), + compute: func(in *statAggregate, out *metricValue) { + out.kind = metricKindUint64 + out.scalar = in.finalStats.finalizersQueued + }, + }, "/gc/scan/globals:bytes": { deps: makeStatDepSet(gcStatsDep), compute: func(in *statAggregate, out *metricValue) { @@ -514,10 +542,11 @@ func godebug_registerMetric(name string, read func() uint64) { type statDep uint const ( - heapStatsDep statDep = iota // corresponds to heapStatsAggregate - sysStatsDep // corresponds to sysStatsAggregate - cpuStatsDep // corresponds to cpuStatsAggregate - gcStatsDep // corresponds to gcStatsAggregate + heapStatsDep statDep = iota // corresponds to heapStatsAggregate + sysStatsDep // corresponds to sysStatsAggregate + cpuStatsDep // corresponds to cpuStatsAggregate + gcStatsDep // corresponds to gcStatsAggregate + finalStatsDep // corresponds to finalStatsAggregate numStatsDeps ) @@ -696,6 +725,21 @@ func (a *gcStatsAggregate) compute() { a.totalScan = a.heapScan + a.stackScan + a.globalsScan } +// finalStatsAggregate represents various finalizer/cleanup stats obtained +// from the runtime acquired together to avoid skew and inconsistencies. +type finalStatsAggregate struct { + finalizersQueued uint64 + finalizersExecuted uint64 + cleanupsQueued uint64 + cleanupsExecuted uint64 +} + +// compute populates the finalStatsAggregate with values from the runtime. +func (a *finalStatsAggregate) compute() { + a.finalizersQueued, a.finalizersExecuted = finReadQueueStats() + a.cleanupsQueued, a.cleanupsExecuted = gcCleanups.readQueueStats() +} + // nsToSec takes a duration in nanoseconds and converts it to seconds as // a float64. func nsToSec(ns int64) float64 { @@ -708,11 +752,12 @@ func nsToSec(ns int64) float64 { // as a set of these aggregates that it has populated. The aggregates // are populated lazily by its ensure method. type statAggregate struct { - ensured statDepSet - heapStats heapStatsAggregate - sysStats sysStatsAggregate - cpuStats cpuStatsAggregate - gcStats gcStatsAggregate + ensured statDepSet + heapStats heapStatsAggregate + sysStats sysStatsAggregate + cpuStats cpuStatsAggregate + gcStats gcStatsAggregate + finalStats finalStatsAggregate } // ensure populates statistics aggregates determined by deps if they @@ -735,6 +780,8 @@ func (a *statAggregate) ensure(deps *statDepSet) { a.cpuStats.compute() case gcStatsDep: a.gcStats.compute() + case finalStatsDep: + a.finalStats.compute() } } a.ensured = a.ensured.union(missing) diff --git a/src/runtime/metrics/description.go b/src/runtime/metrics/description.go index 19a7dbf07a..4587f791e1 100644 --- a/src/runtime/metrics/description.go +++ b/src/runtime/metrics/description.go @@ -174,6 +174,22 @@ var allDesc = []Description{ Kind: KindFloat64, Cumulative: true, }, + { + Name: "/gc/cleanups/executed:cleanups", + Description: "Approximate total count of cleanup functions (created by runtime.AddCleanup) " + + "executed by the runtime. Subtract /gc/cleanups/queued:cleanups to approximate " + + "cleanup queue length. Useful for detecting slow cleanups holding up the queue.", + Kind: KindUint64, + Cumulative: true, + }, + { + Name: "/gc/cleanups/queued:cleanups", + Description: "Approximate total count of cleanup functions (created by runtime.AddCleanup) " + + "queued by the runtime for execution. Subtract from /gc/cleanups/executed:cleanups " + + "to approximate cleanup queue length. Useful for detecting slow cleanups holding up the queue.", + Kind: KindUint64, + Cumulative: true, + }, { Name: "/gc/cycles/automatic:gc-cycles", Description: "Count of completed GC cycles generated by the Go runtime.", @@ -192,6 +208,23 @@ var allDesc = []Description{ Kind: KindUint64, Cumulative: true, }, + { + Name: "/gc/finalizers/executed:finalizers", + Description: "Total count of finalizer functions (created by runtime.SetFinalizer) " + + "executed by the runtime. Subtract /gc/finalizers/queued:finalizers to approximate " + + "finalizer queue length. Useful for detecting finalizers overwhelming the queue, " + + "either by being too slow, or by there being too many of them.", + Kind: KindUint64, + Cumulative: true, + }, + { + Name: "/gc/finalizers/queued:finalizers", + Description: "Total count of finalizer functions (created by runtime.SetFinalizer) and " + + "queued by the runtime for execution. Subtract from /gc/finalizers/executed:finalizers " + + "to approximate finalizer queue length. Useful for detecting slow finalizers holding up the queue.", + Kind: KindUint64, + Cumulative: true, + }, { Name: "/gc/gogc:percent", Description: "Heap size target percentage configured by the user, otherwise 100. This " + diff --git a/src/runtime/metrics/doc.go b/src/runtime/metrics/doc.go index a1902bc6d7..058769ac3a 100644 --- a/src/runtime/metrics/doc.go +++ b/src/runtime/metrics/doc.go @@ -137,6 +137,19 @@ Below is the full list of supported metrics, ordered lexicographically. to system CPU time measurements. Compare only with other /cpu/classes metrics. + /gc/cleanups/executed:cleanups + Approximate total count of cleanup functions (created + by runtime.AddCleanup) executed by the runtime. Subtract + /gc/cleanups/queued:cleanups to approximate cleanup queue + length. Useful for detecting slow cleanups holding up the queue. + + /gc/cleanups/queued:cleanups + Approximate total count of cleanup functions (created by + runtime.AddCleanup) queued by the runtime for execution. + Subtract from /gc/cleanups/executed:cleanups to approximate + cleanup queue length. Useful for detecting slow cleanups holding + up the queue. + /gc/cycles/automatic:gc-cycles Count of completed GC cycles generated by the Go runtime. @@ -146,6 +159,20 @@ Below is the full list of supported metrics, ordered lexicographically. /gc/cycles/total:gc-cycles Count of all completed GC cycles. + /gc/finalizers/executed:finalizers + Total count of finalizer functions (created by + runtime.SetFinalizer) executed by the runtime. Subtract + /gc/finalizers/queued:finalizers to approximate finalizer queue + length. Useful for detecting finalizers overwhelming the queue, + either by being too slow, or by there being too many of them. + + /gc/finalizers/queued:finalizers + Total count of finalizer functions (created by + runtime.SetFinalizer) and queued by the runtime for execution. + Subtract from /gc/finalizers/executed:finalizers to approximate + finalizer queue length. Useful for detecting slow finalizers + holding up the queue. + /gc/gogc:percent Heap size target percentage configured by the user, otherwise 100. This value is set by the GOGC environment variable, and the diff --git a/src/runtime/metrics_test.go b/src/runtime/metrics_test.go index 5fc022efc6..5787c96084 100644 --- a/src/runtime/metrics_test.go +++ b/src/runtime/metrics_test.go @@ -499,6 +499,10 @@ func TestReadMetricsCumulative(t *testing.T) { defer wg.Done() for { // Add more things here that could influence metrics. + for i := 0; i < 10; i++ { + runtime.AddCleanup(new(*int), func(_ struct{}) {}, struct{}{}) + runtime.SetFinalizer(new(*int), func(_ **int) {}) + } for i := 0; i < len(readMetricsSink); i++ { readMetricsSink[i] = make([]byte, 1024) select { @@ -1512,3 +1516,62 @@ func TestMetricHeapUnusedLargeObjectOverflow(t *testing.T) { done <- struct{}{} wg.Wait() } + +func TestReadMetricsCleanups(t *testing.T) { + runtime.GC() // End any in-progress GC. + runtime.BlockUntilEmptyCleanupQueue(int64(1 * time.Second)) // Flush any queued cleanups. + + var before [2]metrics.Sample + before[0].Name = "/gc/cleanups/queued:cleanups" + before[1].Name = "/gc/cleanups/executed:cleanups" + after := before + + metrics.Read(before[:]) + + const N = 10 + for i := 0; i < N; i++ { + runtime.AddCleanup(new(*int), func(_ struct{}) {}, struct{}{}) + } + + runtime.GC() + runtime.BlockUntilEmptyCleanupQueue(int64(1 * time.Second)) + + metrics.Read(after[:]) + + if v0, v1 := before[0].Value.Uint64(), after[0].Value.Uint64(); v0+N != v1 { + t.Errorf("expected %s difference to be exactly %d, got %d -> %d", before[0].Name, N, v0, v1) + } + if v0, v1 := before[1].Value.Uint64(), after[1].Value.Uint64(); v0+N != v1 { + t.Errorf("expected %s difference to be exactly %d, got %d -> %d", before[1].Name, N, v0, v1) + } +} + +func TestReadMetricsFinalizers(t *testing.T) { + runtime.GC() // End any in-progress GC. + runtime.BlockUntilEmptyFinalizerQueue(int64(1 * time.Second)) // Flush any queued finalizers. + + var before [2]metrics.Sample + before[0].Name = "/gc/finalizers/queued:finalizers" + before[1].Name = "/gc/finalizers/executed:finalizers" + after := before + + metrics.Read(before[:]) + + const N = 10 + for i := 0; i < N; i++ { + runtime.SetFinalizer(new(*int), func(_ **int) {}) + } + + runtime.GC() + runtime.GC() + runtime.BlockUntilEmptyFinalizerQueue(int64(1 * time.Second)) + + metrics.Read(after[:]) + + if v0, v1 := before[0].Value.Uint64(), after[0].Value.Uint64(); v0+N != v1 { + t.Errorf("expected %s difference to be exactly %d, got %d -> %d", before[0].Name, N, v0, v1) + } + if v0, v1 := before[1].Value.Uint64(), after[1].Value.Uint64(); v0+N != v1 { + t.Errorf("expected %s difference to be exactly %d, got %d -> %d", before[1].Name, N, v0, v1) + } +}