Skip to content

[WIP] fix: labeled cache result metrics + stop Vary-sentinel from polluting L2 hit-rate - #4364

Closed
larry-dalmeida wants to merge 6 commits into
zalando:masterfrom
larry-dalmeida:feat/LWSRE-895-cache-result-metrics
Closed

larry-dalmeida wants to merge 6 commits into
zalando:masterfrom
larry-dalmeida:feat/LWSRE-895-cache-result-metrics

Conversation

@larry-dalmeida

Copy link
Copy Markdown
Collaborator

Summary

Two related, additive changes to the cache() filter's observability:

  1. Labeled cache result metrics — adds skipper_cache_result_total{result="hit|miss|stale", code_class="2xx|4xx|5xx|other"} and skipper_cache_lru_bytes{route="..."}, alongside the existing flat cache.* counters (zero migration risk — nothing existing changes shape).
  2. Vary-sentinel L2 hit-rate pollution fix — Request() unconditionally looked up a Vary-sentinel key ("vary:"+baseKey) through the same metrics-instrumented Storage.Get() used for real content lookups, before any hit/miss/stale classification. For any route whose origin never sends a Vary header, that lookup is a guaranteed miss on every single request, inflating l2_miss (and therefore deflating the L2 Hit Rate panel) independent of real cache effectiveness. The sentinel lookup no longer goes through the metrics-instrumented path.

Why

Driven by an observability investigation on a Lounge-owned cache() deployment: the "L2 Hit Rate" panel on our Skipper Cache Health dashboard read a flat ~12%, which looked alarming but didn't reconcile with L1 already serving ~85-87% of hits. Root-caused to the Vary-sentinel mechanism above — confirmed via live production counters (l2_miss ≈ total request volume, 1:1) and via filters/cache/filter.go source (the sentinel's matching Set() only fires when the origin actually sent Vary, so an origin that never does leaves the sentinel key permanently absent).

Separately, operators asked for status-code-aware cache visibility (today's flat cache.hit/cache.miss/cache.stale counters can't distinguish "served a healthy 200" from "served a cached 4xx/5xx") and a per-route breakdown of LRU memory consumption — both addressed by the new labeled metrics.

Changes

  • filters/cache/filter.go — emit skipper_cache_result_total/skipper_cache_lru_bytes at cache decision points; route the Vary-sentinel lookup around the metrics-instrumented Storage.Get() path.
  • filters/cache/l2_storage.go, lru_storage.go, storage.go — plumbing for the metrics-skipping sentinel lookup.
  • metrics/prometheus.go — register the new CounterVec/GaugeVec.
  • filters/cache/filter_test.go, l2_storage_valkey_test.go — new tests covering both changes.
  • docs/operation/operation.md — document the new metric labels and cardinality.

Verification

  • go build ./... clean.
  • go test ./filters/cache/... ./metrics/... — all pass except TestValkeyStorage_GetSetDelete / TestValkeyStorage_FallsBackToL1OnValkeyUnavailable, which fail in this sandbox on rootless Docker not found (testcontainers can't start a Valkey container here) — pre-existing environment limitation, not exercised by either change in this PR.
  • Cardinality: skipper_cache_result_total is bounded at 3×4=12 series; skipper_cache_lru_bytes is bounded by route count (tens to hundreds, same order as skipper's existing per-route metrics).

Rollout

  • Backward compatible: existing flat cache.* counters are unchanged; both changes are purely additive/corrective.
  • No feature flag needed.
  • Ref: LWSRE-895

Implements fine-grained observability for cache filter results by HTTP
status code class via ScopedPrometheusRegisterer.

New metrics:
- skipper_cache_result_total{result, code_class} counter
- skipper_cache_lru_bytes{route} gauge

Cardinality bounded: 3 result types × 4 code_class values = 12 series max.
Backward compatible: existing flat-key counters still emitted.

LWSRE-214

Signed-off-by: Larry D Almeida <hello@larrydalmeida.com>
Add comprehensive tests for new labeled cache metrics across all
code_class values and cache result types (hit/miss/stale).
Document new skipper_cache_result_total and skipper_cache_lru_bytes
metrics in operation guide.

LWSRE-214

Signed-off-by: Larry D Almeida <hello@larrydalmeida.com>
…2_get_error

Request()'s Vary-sentinel check ("vary:"+baseKey) was routed through the
regular, metrics-instrumented Storage.Get(). That lookup runs on every
single request, regardless of whether a real cache decision is being
made, so it was counting as a cache outcome on every request -
inflating l1_hit/l2_hit/l2_miss/l2_get_error (plain and labeled) with
internal plumbing noise rather than real caching behavior.

Add Storage.GetSilent(), implemented by both LRUStorage (delegates to
Get - it records no metrics of its own) and L2Storage (shares Get's
logic via a new internal get(recordMetrics bool), skipping only the
outcome-metric calls; L1 write-through warming still runs on a silent
hit, since that's a caching side effect of the read, not an outcome
metric). filter.go's sentinel lookup now calls GetSilent instead of Get.

LWSRE-214

Signed-off-by: Larry D Almeida <hello@larrydalmeida.com>
coalesce() had zero timing instrumentation despite being the thundering-
herd protection point for cold misses. Measure from right after the
singleflight DoChan call to when the result channel yields - near-zero
for the leader (it computes the result itself), the leader's real fetch
time for followers waiting on it. Same MeasureSince/customHistogramM
mechanism as the existing cache.reval_wait_duration/cache.reval_duration.

LWSRE-214

Signed-off-by: Larry D Almeida <hello@larrydalmeida.com>
L2Storage only had pass/fail counters (l2_hit, l2_miss, l2_get_error,
l2_set_fallback) - no timing. Measure the underlying Valkey/Redis
Get/SetWithExpire round-trip directly, on every call including internal
lookups like the Vary-sentinel check, via the existing MeasureSince/
customHistogramM mechanism (same convention as
cache.reval_wait_duration/cache.reval_duration/cache.coalesce_wait_duration).

Verified locally against a real Valkey instance: -enable-l2-cache alone
is not sufficient to exercise this - selectL2CacheClient only runs inside
skipper.go's `if o.EnableSwarm` block, so -enable-swarm is also required
or L2Storage is never constructed and cache() silently falls back to
L1-only. Noted this in the local verification setup's README.

LWSRE-214

Signed-off-by: Larry D Almeida <hello@larrydalmeida.com>
cache.storage_error was a single unlabeled counter incremented from 9
generic call sites in filter.go, none of which know whether f.storage is
LRUStorage (L1) or L2Storage (L2) - backend was unknowable there. 4 of
those 9 (all on the Delete path) could never fire: LRUStorage.Delete
always returns nil, and L2Storage.Delete only ever returns nil to its
caller too (L1 delete always runs after a best-effort L2 delete).

Added IncStorageError(backend, op) -> skipper_cache_storage_error_total
{backend, op}, called from the storage implementations themselves where
backend is actually known: LRUStorage.Set/Get (encode/decode failure),
L2Storage.Set/Get (encode/decode failure), L2Storage.Delete (the real L2
failure, previously only visible as the generic unlabeled counter).
IncStorageError also increments the pre-existing flat cache.storage_error
counter and the labeled skipper_cache_result_total{result="storage_error"}
metric from this one call site, so existing consumers of either see zero
behavior change - this only adds backend/op attribution going forward.

Removed filter.go's 9 generic increments now that the storage layer
self-reports (keeping both would double-count). Updated the 7 existing
tests that asserted on those generic increments via a backend-opaque
test double (failingSetStorage/failingDeleteStorage) - a failure from
code that isn't a real LRUStorage/L2Storage genuinely can't be
attributed, so they now assert no metric fires, only that the request
is still served and nothing panics. Added real attribution tests for the
LRUStorage/L2Storage failure paths.

LWSRE-214

Signed-off-by: Larry D Almeida <hello@larrydalmeida.com>
@larry-dalmeida larry-dalmeida changed the title fix: labeled cache result metrics + stop Vary-sentinel from polluting L2 hit-rate [WIP] fix: labeled cache result metrics + stop Vary-sentinel from polluting L2 hit-rate Oct 21, 2026
@larry-dalmeida

Copy link
Copy Markdown
Collaborator Author

Superseeded by #4369

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant