From 18158d18dfc4e14395f665c298eac3a60d7d4282 Mon Sep 17 00:00:00 2001 From: AdaAibaby Date: Mon, 24 Aug 2026 17:14:15 +0800 Subject: [PATCH] obs(api): add expiration index size and evictor sweep duration metrics MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Closes #3605. Two new histograms: api.redis_storage.expiration_index.size ({entry}) ZCARD of sandbox:storage:global:expiration sampled once per heal pass (every 5 min). Use max/p99 to detect unbounded growth caused by stale ZSET entries that are not being swept. api.redis_storage.expiration_index.sweep_duration (ms) Wall-clock duration of each ExpiredItems call (ZRANGEBYSCORE + MGET pipeline). Rising p99 alongside rising index size confirms the O(log N + K) cost growth described in #3605. Collection points: - heal.go: ZCARD after each healExpirationIndex pass — one extra Redis round-trip per 5 min, negligible next to forEachSandboxBatch. - items.go: defer-based timer wrapping the full ExpiredItems body, recorded on every evictor tick. --- .../internal/sandbox/storage/redis/heal.go | 9 ++++++ .../internal/sandbox/storage/redis/items.go | 7 +++- .../internal/sandbox/storage/redis/main.go | 17 ++++++++++ packages/shared/pkg/telemetry/meters.go | 32 ++++++++++++++----- 4 files changed, 56 insertions(+), 9 deletions(-) diff --git a/packages/api/internal/sandbox/storage/redis/heal.go b/packages/api/internal/sandbox/storage/redis/heal.go index d4cf891662..793e0c2246 100644 --- a/packages/api/internal/sandbox/storage/redis/heal.go +++ b/packages/api/internal/sandbox/storage/redis/heal.go @@ -100,6 +100,15 @@ func (s *Storage) healExpirationIndex(ctx context.Context) (int, teamWalk, error } walk.complete = skipped == 0 + // Sample the ZSET cardinality once per heal pass. A single ZCARD piggybacked + // here costs one Redis round-trip every 5 min — negligible next to the + // forEachSandboxBatch scan that precedes it. + if n, zErr := s.redisClient.ZCard(ctx, globalExpirationSet).Result(); zErr == nil { + s.metrics.indexSize.Record(ctx, n) + } else { + logger.L().Warn(ctx, "Failed to sample expiration index size", zap.Error(zErr)) + } + return healed, walk, nil } diff --git a/packages/api/internal/sandbox/storage/redis/items.go b/packages/api/internal/sandbox/storage/redis/items.go index 5549262218..c9149e9288 100644 --- a/packages/api/internal/sandbox/storage/redis/items.go +++ b/packages/api/internal/sandbox/storage/redis/items.go @@ -55,7 +55,12 @@ func membersOf(refs []memberRef) []any { // ExpiredItems returns running sandboxes whose EndTime has passed. // It bounds per-cycle work via LIMIT and cleans up orphaned ZSET entries. func (s *Storage) ExpiredItems(ctx context.Context) ([]sandboxtypes.Sandbox, error) { - now := time.Now() + sweepStart := time.Now() + defer func() { + s.metrics.sweepDuration.Record(ctx, time.Since(sweepStart).Milliseconds()) + }() + + now := sweepStart nowMs := float64(now.UnixMilli()) // Fetch members whose score (EndTime in ms) is <= now, bounded to 256 per cycle. diff --git a/packages/api/internal/sandbox/storage/redis/main.go b/packages/api/internal/sandbox/storage/redis/main.go index d4f1e74afe..25698ee206 100644 --- a/packages/api/internal/sandbox/storage/redis/main.go +++ b/packages/api/internal/sandbox/storage/redis/main.go @@ -84,6 +84,11 @@ type expirationIndexMetrics struct { sweptOrphan metric.MeasurementOption sweptDeadExecution metric.MeasurementOption sweptInvalid metric.MeasurementOption + + // indexSize records the ZSET cardinality once per heal pass (every 5 min). + indexSize metric.Int64Histogram + // sweepDuration records wall-clock time of each ExpiredItems call. + sweepDuration metric.Int64Histogram } const sweptReasonAttr = "reason" @@ -109,6 +114,16 @@ func newExpirationIndexMetrics(meter metric.Meter) (expirationIndexMetrics, erro return expirationIndexMetrics{}, fmt.Errorf("expiration index swept counter: %w", err) } + indexSize, err := telemetry.GetHistogram(meter, telemetry.ApiRedisStorageExpirationIndexSize) + if err != nil { + return expirationIndexMetrics{}, fmt.Errorf("expiration index size histogram: %w", err) + } + + sweepDuration, err := telemetry.GetHistogram(meter, telemetry.ApiRedisStorageExpirationIndexSweepDuration) + if err != nil { + return expirationIndexMetrics{}, fmt.Errorf("expiration index sweep duration histogram: %w", err) + } + return expirationIndexMetrics{ indexHealed: healed, indexRescored: rescored, @@ -117,6 +132,8 @@ func newExpirationIndexMetrics(meter metric.Meter) (expirationIndexMetrics, erro sweptOrphan: metric.WithAttributeSet(attribute.NewSet(attribute.String(sweptReasonAttr, "orphan"))), sweptDeadExecution: metric.WithAttributeSet(attribute.NewSet(attribute.String(sweptReasonAttr, "dead_execution"))), sweptInvalid: metric.WithAttributeSet(attribute.NewSet(attribute.String(sweptReasonAttr, "invalid"))), + indexSize: indexSize, + sweepDuration: sweepDuration, }, nil } diff --git a/packages/shared/pkg/telemetry/meters.go b/packages/shared/pkg/telemetry/meters.go index d0fbf8d51a..cc6e1c13e1 100644 --- a/packages/shared/pkg/telemetry/meters.go +++ b/packages/shared/pkg/telemetry/meters.go @@ -739,6 +739,18 @@ const ( ) const ( + // ApiRedisStorageExpirationIndexSize records the cardinality of the global + // expiration ZSET (sandbox:storage:global:expiration) once per heal pass. + // Use the max/p99 to detect unbounded growth; a rising trend without a + // corresponding rise in live sandbox count indicates stale entries are + // accumulating faster than they are swept. + ApiRedisStorageExpirationIndexSize HistogramType = "api.redis_storage.expiration_index.size" + + // ApiRedisStorageExpirationIndexSweepDuration records the wall-clock time + // of each ExpiredItems call (ZRANGEBYSCORE + MGET pipeline). Rising p99 + // alongside a rising expiration_index.size confirms O(log N + K) growth. + ApiRedisStorageExpirationIndexSweepDuration HistogramType = "api.redis_storage.expiration_index.sweep_duration" + ApiRedisStoragePublisherPublishDuration HistogramType = "api.redis_storage.publisher.publish.duration" // ApiRedisScriptDuration is the round trip of one Lua script run against // the sandbox store, by script (see ApiRedisScriptCalls). @@ -1299,10 +1311,12 @@ func GetGaugeInt(meter metric.Meter, name GaugeIntType) (metric.Int64ObservableG } var histogramDesc = map[HistogramType]string{ - ApiRedisStoragePublisherPublishDuration: "Duration of a single Redis PUBLISH round-trip from the storage publisher", - ApiRedisScriptDuration: "Round trip of one Lua script run against the sandbox store, by script", - ApiSandboxListAge: "Age of a served sandbox list: the store sweep's duration for a read, the wait from the sweep's start for a joined (shared) read, the snapshot's lag for a hit", - ApiRedisStorageListGets: "Commands one bulk record read issued, by the sandbox list, the evictor or the node reconcile: one GET per record on the sandbox-tagged keys", + ApiRedisStorageExpirationIndexSize: "Cardinality of sandbox:storage:global:expiration ZSET at the time of each heal pass; use max/p99 to detect unbounded growth", + ApiRedisStorageExpirationIndexSweepDuration: "Wall-clock duration of one ExpiredItems call (ZRANGEBYSCORE + MGET pipeline); rising p99 alongside rising index size confirms O(log N) growth", + ApiRedisStoragePublisherPublishDuration: "Duration of a single Redis PUBLISH round-trip from the storage publisher", + ApiRedisScriptDuration: "Round trip of one Lua script run against the sandbox store, by script", + ApiSandboxListAge: "Age of a served sandbox list: the store sweep's duration for a read, the wait from the sweep's start for a joined (shared) read, the snapshot's lag for a hit", + ApiRedisStorageListGets: "Commands one bulk record read issued, by the sandbox list, the evictor or the node reconcile: one GET per record on the sandbox-tagged keys", FPHRunDurationName: "Duration of a completed free-page-hinting drain or run, labeled by phase", FPHStopDurationName: "Duration of the stop of an abandoned hinting cycle, acknowledgement wait included", @@ -1398,10 +1412,12 @@ var histogramDesc = map[HistogramType]string{ } var histogramUnits = map[HistogramType]string{ - ApiRedisStoragePublisherPublishDuration: "ms", - ApiRedisScriptDuration: "ms", - ApiSandboxListAge: "ms", - ApiRedisStorageListGets: "{command}", + ApiRedisStorageExpirationIndexSize: "{entry}", + ApiRedisStorageExpirationIndexSweepDuration: "ms", + ApiRedisStoragePublisherPublishDuration: "ms", + ApiRedisScriptDuration: "ms", + ApiSandboxListAge: "ms", + ApiRedisStorageListGets: "{command}", FPHRunDurationName: "ms", FPHStopDurationName: "ms",