Skip to content

Commit 5ee0e63

Browse files
committed
obs(api): add expiration index size and evictor sweep duration metrics
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.
1 parent 110fa5b commit 5ee0e63

4 files changed

Lines changed: 50 additions & 3 deletions

File tree

‎packages/api/internal/sandbox/storage/redis/heal.go‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -83,6 +83,15 @@ func (s *Storage) healExpirationIndex(ctx context.Context) (int, error) {
8383
return healed, err
8484
}
8585

86+
// Sample the ZSET cardinality once per heal pass. A single ZCARD piggybacked
87+
// here costs one Redis round-trip every 5 min — negligible next to the
88+
// forEachSandboxBatch scan that precedes it.
89+
if n, zErr := s.redisClient.ZCard(ctx, globalExpirationSet).Result(); zErr == nil {
90+
s.metrics.indexSize.Record(ctx, n)
91+
} else {
92+
logger.L().Warn(ctx, "Failed to sample expiration index size", zap.Error(zErr))
93+
}
94+
8695
return healed, nil
8796
}
8897

‎packages/api/internal/sandbox/storage/redis/items.go‎

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,12 @@ const expiredItemsBatchSize = 256
1818
// ExpiredItems returns running sandboxes whose EndTime has passed.
1919
// It bounds per-cycle work via LIMIT and cleans up orphaned ZSET entries.
2020
func (s *Storage) ExpiredItems(ctx context.Context) ([]sandboxtypes.Sandbox, error) {
21-
now := time.Now()
21+
sweepStart := time.Now()
22+
defer func() {
23+
s.metrics.sweepDuration.Record(ctx, time.Since(sweepStart).Milliseconds())
24+
}()
25+
26+
now := sweepStart
2227
nowMs := float64(now.UnixMilli())
2328

2429
// Fetch members whose score (EndTime in ms) is <= now, bounded to 256 per cycle.

‎packages/api/internal/sandbox/storage/redis/main.go‎

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,11 @@ type expirationIndexMetrics struct {
5353
sweptOrphan metric.MeasurementOption
5454
sweptDeadExecution metric.MeasurementOption
5555
sweptInvalid metric.MeasurementOption
56+
57+
// indexSize records the ZSET cardinality once per heal pass (every 5 min).
58+
indexSize metric.Int64Histogram
59+
// sweepDuration records wall-clock time of each ExpiredItems call.
60+
sweepDuration metric.Int64Histogram
5661
}
5762

5863
const sweptReasonAttr = "reason"
@@ -73,13 +78,25 @@ func newExpirationIndexMetrics(meter metric.Meter) (expirationIndexMetrics, erro
7378
return expirationIndexMetrics{}, fmt.Errorf("expiration index swept counter: %w", err)
7479
}
7580

81+
indexSize, err := telemetry.GetHistogram(meter, telemetry.ApiRedisStorageExpirationIndexSize)
82+
if err != nil {
83+
return expirationIndexMetrics{}, fmt.Errorf("expiration index size histogram: %w", err)
84+
}
85+
86+
sweepDuration, err := telemetry.GetHistogram(meter, telemetry.ApiRedisStorageExpirationIndexSweepDuration)
87+
if err != nil {
88+
return expirationIndexMetrics{}, fmt.Errorf("expiration index sweep duration histogram: %w", err)
89+
}
90+
7691
return expirationIndexMetrics{
7792
indexHealed: healed,
7893
indexRescored: rescored,
7994
indexSwept: swept,
8095
sweptOrphan: metric.WithAttributeSet(attribute.NewSet(attribute.String(sweptReasonAttr, "orphan"))),
8196
sweptDeadExecution: metric.WithAttributeSet(attribute.NewSet(attribute.String(sweptReasonAttr, "dead_execution"))),
8297
sweptInvalid: metric.WithAttributeSet(attribute.NewSet(attribute.String(sweptReasonAttr, "invalid"))),
98+
indexSize: indexSize,
99+
sweepDuration: sweepDuration,
83100
}, nil
84101
}
85102

‎packages/shared/pkg/telemetry/meters.go‎

Lines changed: 18 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -279,6 +279,18 @@ const (
279279
)
280280

281281
const (
282+
// ApiRedisStorageExpirationIndexSize records the cardinality of the global
283+
// expiration ZSET (sandbox:storage:global:expiration) once per heal pass.
284+
// Use the max/p99 to detect unbounded growth; a rising trend without a
285+
// corresponding rise in live sandbox count indicates stale entries are
286+
// accumulating faster than they are swept.
287+
ApiRedisStorageExpirationIndexSize HistogramType = "api.redis_storage.expiration_index.size"
288+
289+
// ApiRedisStorageExpirationIndexSweepDuration records the wall-clock time
290+
// of each ExpiredItems call (ZRANGEBYSCORE + MGET pipeline). Rising p99
291+
// alongside a rising expiration_index.size confirms O(log N + K) growth.
292+
ApiRedisStorageExpirationIndexSweepDuration HistogramType = "api.redis_storage.expiration_index.sweep_duration"
293+
282294
ApiRedisStoragePublisherPublishDuration HistogramType = "api.redis_storage.publisher.publish.duration"
283295

284296
// Firecracker net histograms — per-sandbox distribution per metrics flush, no sandbox_id.
@@ -560,7 +572,9 @@ func GetGaugeInt(meter metric.Meter, name GaugeIntType) (metric.Int64ObservableG
560572
}
561573

562574
var histogramDesc = map[HistogramType]string{
563-
ApiRedisStoragePublisherPublishDuration: "Duration of a single Redis PUBLISH round-trip from the storage publisher",
575+
ApiRedisStorageExpirationIndexSize: "Cardinality of sandbox:storage:global:expiration ZSET at the time of each heal pass; use max/p99 to detect unbounded growth",
576+
ApiRedisStorageExpirationIndexSweepDuration: "Wall-clock duration of one ExpiredItems call (ZRANGEBYSCORE + MGET pipeline); rising p99 alongside rising index size confirms O(log N) growth",
577+
ApiRedisStoragePublisherPublishDuration: "Duration of a single Redis PUBLISH round-trip from the storage publisher",
564578

565579
BuildDurationHistogramName: "Time taken to build a template",
566580
BuildPhaseDurationHistogramName: "Time taken to build each phase of a template",
@@ -629,7 +643,9 @@ var histogramDesc = map[HistogramType]string{
629643
}
630644

631645
var histogramUnits = map[HistogramType]string{
632-
ApiRedisStoragePublisherPublishDuration: "ms",
646+
ApiRedisStorageExpirationIndexSize: "{entry}",
647+
ApiRedisStorageExpirationIndexSweepDuration: "ms",
648+
ApiRedisStoragePublisherPublishDuration: "ms",
633649

634650
BuildDurationHistogramName: "ms",
635651
BuildPhaseDurationHistogramName: "ms",

0 commit comments

Comments
 (0)